The WARNs at the end are just telling you that it tried to close the session but it was already closed. The rest is just general Zookeeper info.
J-D On Wed, Feb 3, 2010 at 1:00 AM, zward3x <pasalic.zahar...@gmail.com> wrote: > > Hi, > > i'm runing hbase (0.20.3) in non distributed mode. I can access hbase via > hbase shell (create, put, get, scan it looks ok). But when i'm accessing > from client (jruby calling hbase api) i'm geting stack trace but only at > the > end of my program. I looks that everithing is done - i can see scan or put > results but at the end i'm geting stack trace. Also it seems that i'm not > getting ERROR log but WARN. (Note that same code works fine on version > 0.20.1) > > Here is client log: > > 10/02/03 09:46:25 INFO zookeeper.ZooKeeper: Client > environment:zookeeper.version=3.2.2-888565, built on 12/08/2009 21:51 GMT > 10/02/03 09:46:25 INFO zookeeper.ZooKeeper: Client > environment:host.name=192.168.0.2 > 10/02/03 09:46:25 INFO zookeeper.ZooKeeper: Client > environment:java.version=1.6.0_15 > 10/02/03 09:46:25 INFO zookeeper.ZooKeeper: Client > environment:java.vendor=Apple Inc. > 10/02/03 09:46:25 INFO zookeeper.ZooKeeper: Client > > environment:java.home=/System/Library/Frameworks/JavaVM.framework/Versions/1.6.0/Home > 10/02/03 09:46:25 INFO zookeeper.ZooKeeper: Client > environment:java.class.path=/Applications/NetBeans/NetBeans > > 6.8.app/Contents/Resources/NetBeans/ruby2/jruby-1.4.0/lib/jruby.jar:/Applications/NetBeans/NetBeans > > 6.8.app/Contents/Resources/NetBeans/ruby2/jruby-1.4.0/lib/profile.jar:/usr/lib/hbase-0.20.3/lib/AgileJSON-2009-03-30.jar:/usr/lib/hbase-0.20.3/lib/commons-cli-2.0-SNAPSHOT.jar:/usr/lib/hbase-0.20.3/lib/commons-el-from-jetty-5.1.4.jar:/usr/lib/hbase-0.20.3/lib/commons-httpclient-3.0.1.jar:/usr/lib/hbase-0.20.3/lib/commons-logging-1.0.4.jar:/usr/lib/hbase-0.20.3/lib/commons-logging-api-1.0.4.jar:/usr/lib/hbase-0.20.3/lib/commons-math-1.1.jar:/usr/lib/hbase-0.20.3/lib/hadoop-0.20.1-hdfs127-core.jar:/usr/lib/hbase-0.20.3/lib/hadoop-0.20.1-test.jar:/usr/lib/hbase-0.20.3/lib/jasper-compiler-5.5.12.jar:/usr/lib/hbase-0.20.3/lib/jasper-runtime-5.5.12.jar:/usr/lib/hbase-0.20.3/lib/jetty-6.1.14.jar:/usr/lib/hbase-0.20.3/lib/jetty-util-6.1.14.jar:/usr/lib/hbase-0.20.3/lib/jruby-complete-1.2.0.jar:/usr/lib/hbase-0.20.3/lib/json.jar:/usr/lib/hbase-0.20.3/lib/junit-3.8.1.jar:/usr/lib/hbase-0.20.3/lib/libthrift-r771587.jar:/usr/lib/hbase-0.20.3/lib/log4j-1.2.15.jar:/usr/lib/hbase-0.20.3/lib/lucene-core-2.2.0.jar:/usr/lib/hbase-0.20.3/lib/servlet-api-2.5-6.1.14.jar:/usr/lib/hbase-0.20.3/lib/xmlenc-0.52.jar:/usr/lib/hbase-0.20.3/lib/zookeeper-3.2.2.jar:/usr/lib/hbase-0.20.3/hbase-0.20.3.jar:/usr/lib/hbase-0.20.3/conf > 10/02/03 09:46:25 INFO zookeeper.ZooKeeper: Client > > environment:java.library.path=.:/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java > 10/02/03 09:46:25 INFO zookeeper.ZooKeeper: Client > > environment:java.io.tmpdir=/var/folders/bZ/bZ9NjEt6EEOL8obSel2K0E+++TI/-Tmp-/ > 10/02/03 09:46:25 INFO zookeeper.ZooKeeper: Client > environment:java.compiler=<NA> > 10/02/03 09:46:25 INFO zookeeper.ZooKeeper: Client environment:os.name=Mac > OS X > 10/02/03 09:46:25 INFO zookeeper.ZooKeeper: Client > environment:os.arch=x86_64 > 10/02/03 09:46:25 INFO zookeeper.ZooKeeper: Client > environment:os.version=10.6 > 10/02/03 09:46:25 INFO zookeeper.ZooKeeper: Client > environment:user.name=zaharije > 10/02/03 09:46:25 INFO zookeeper.ZooKeeper: Client > environment:user.home=/Users/zaharije > 10/02/03 09:46:25 INFO zookeeper.ZooKeeper: Client > environment:user.dir=/Users/zaharije/NetBeansProjects/RailsApplication1 > 10/02/03 09:46:25 INFO zookeeper.ZooKeeper: Initiating client connection, > connectString=localhost:2181 sessionTimeout=60000 > > watcher=org.apache.hadoop.hbase.client.hconnectionmanager$clientzkwatc...@21e3cc77 > 10/02/03 09:46:25 INFO zookeeper.ClientCnxn: > zookeeper.disableAutoWatchReset > is false > 10/02/03 09:46:25 INFO zookeeper.ClientCnxn: Attempting connection to > server > localhost/fe80:0:0:0:0:0:0:1%1:2181 > 10/02/03 09:46:25 INFO zookeeper.ClientCnxn: Priming connection to > java.nio.channels.SocketChannel[connected local=/fe80:0:0:0:0:0:0:1%1:60781 > remote=localhost/fe80:0:0:0:0:0:0:1%1:2181] > 10/02/03 09:46:25 INFO zookeeper.ClientCnxn: Server connection successful > 10/02/03 09:46:26 INFO zookeeper.ZooKeeper: Closing session: > 0x1269300e1560002 > 10/02/03 09:46:26 INFO zookeeper.ClientCnxn: Closing ClientCnxn for > session: > 0x1269300e1560002 > 10/02/03 09:46:26 INFO zookeeper.ClientCnxn: Exception while closing send > thread for session 0x1269300e1560002 : Read error rc = -1 > java.nio.DirectByteBuffer[pos=0 lim=4 cap=4] > 10/02/03 09:46:26 WARN zookeeper.ClientCnxn: Ignoring exception during > shutdown input > java.net.SocketException: Socket is not connected > at sun.nio.ch.SocketChannelImpl.shutdown(Native Method) > at > sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:640) > at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360) > at > org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:999) > at > org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:984) > 10/02/03 09:46:26 INFO zookeeper.ClientCnxn: Disconnecting ClientCnxn for > session: 0x1269300e1560002 > 10/02/03 09:46:26 INFO zookeeper.ZooKeeper: Session: 0x1269300e1560002 > closed > 10/02/03 09:46:26 INFO zookeeper.ClientCnxn: EventThread shut down > > > -------------------------------------------------------------------------------------------- > > And here is logs from hbase (zookeper log): > > Wed Feb 3 09:44:50 CET 2010 Starting zookeeper on hari-mac.local > ulimit -n 256 > 2010-02-03 09:44:53,349 INFO > org.apache.zookeeper.server.ZooKeeperServerMain: Starting server > 2010-02-03 09:44:53,359 INFO org.apache.zookeeper.server.ZooKeeperServer: > Server environment:zookeeper.version=3.2.2-888565, built on 12/08/2009 > 21:51 > GMT > 2010-02-03 09:44:53,360 INFO org.apache.zookeeper.server.ZooKeeperServer: > Server environment:host.name=192.168.0.2 > 2010-02-03 09:44:53,360 INFO org.apache.zookeeper.server.ZooKeeperServer: > Server environment:java.version=1.6.0_15 > 2010-02-03 09:44:53,360 INFO org.apache.zookeeper.server.ZooKeeperServer: > Server environment:java.vendor=Apple Inc. > 2010-02-03 09:44:53,360 INFO org.apache.zookeeper.server.ZooKeeperServer: > Server > > environment:java.home=/System/Library/Frameworks/JavaVM.framework/Versions/1.6.0/Home > 2010-02-03 09:44:53,360 INFO org.apache.zookeeper.server.ZooKeeperServer: > Server > > environment:java.class.path=/usr/lib/hbase-0.20.3/conf:/Library/Java/Home/lib/tools.jar:/usr/lib/hbase-0.20.3/bin/..:/usr/lib/hbase-0.20.3/bin/../hbase-0.20.3-test.jar:/usr/lib/hbase-0.20.3/bin/../hbase-0.20.3.jar:/usr/lib/hbase-0.20.3/bin/../lib/AgileJSON-2009-03-30.jar:/usr/lib/hbase-0.20.3/bin/../lib/commons-cli-2.0-SNAPSHOT.jar:/usr/lib/hbase-0.20.3/bin/../lib/commons-el-from-jetty-5.1.4.jar:/usr/lib/hbase-0.20.3/bin/../lib/commons-httpclient-3.0.1.jar:/usr/lib/hbase-0.20.3/bin/../lib/commons-logging-1.0.4.jar:/usr/lib/hbase-0.20.3/bin/../lib/commons-logging-api-1.0.4.jar:/usr/lib/hbase-0.20.3/bin/../lib/commons-math-1.1.jar:/usr/lib/hbase-0.20.3/bin/../lib/hadoop-0.20.1-hdfs127-core.jar:/usr/lib/hbase-0.20.3/bin/../lib/hadoop-0.20.1-test.jar:/usr/lib/hbase-0.20.3/bin/../lib/jasper-compiler-5.5.12.jar:/usr/lib/hbase-0.20.3/bin/../lib/jasper-runtime-5.5.12.jar:/usr/lib/hbase-0.20.3/bin/../lib/jetty-6.1.14.jar:/usr/lib/hbase-0.20.3/bin/../lib/jetty-util-6.1.14.jar:/usr/lib/hbase-0.20.3/bin/../lib/jruby-complete-1.2.0.jar:/usr/lib/hbase-0.20.3/bin/../lib/json.jar:/usr/lib/hbase-0.20.3/bin/../lib/junit-3.8.1.jar:/usr/lib/hbase-0.20.3/bin/../lib/libthrift-r771587.jar:/usr/lib/hbase-0.20.3/bin/../lib/log4j-1.2.15.jar:/usr/lib/hbase-0.20.3/bin/../lib/lucene-core-2.2.0.jar:/usr/lib/hbase-0.20.3/bin/../lib/servlet-api-2.5-6.1.14.jar:/usr/lib/hbase-0.20.3/bin/../lib/xmlenc-0.52.jar:/usr/lib/hbase-0.20.3/bin/../lib/zookeeper-3.2.2.jar:/usr/lib/hbase-0.20.3/bin/../lib/jsp-2.1/jsp-2.1.jar:/usr/lib/hbase-0.20.3/bin/../lib/jsp-2.1/jsp-api-2.1.jar > 2010-02-03 09:44:53,360 INFO org.apache.zookeeper.server.ZooKeeperServer: > Server > > environment:java.library.path=/usr/lib/hbase-0.20.3/bin/../lib/native/Mac_OS_X-x86_64-64 > 2010-02-03 09:44:53,360 INFO org.apache.zookeeper.server.ZooKeeperServer: > Server > > environment:java.io.tmpdir=/var/folders/bZ/bZ9NjEt6EEOL8obSel2K0E+++TI/-Tmp-/ > 2010-02-03 09:44:53,360 INFO org.apache.zookeeper.server.ZooKeeperServer: > Server environment:java.compiler=<NA> > 2010-02-03 09:44:53,360 INFO org.apache.zookeeper.server.ZooKeeperServer: > Server environment:os.name=Mac OS X > 2010-02-03 09:44:53,360 INFO org.apache.zookeeper.server.ZooKeeperServer: > Server environment:os.arch=x86_64 > 2010-02-03 09:44:53,360 INFO org.apache.zookeeper.server.ZooKeeperServer: > Server environment:os.version=10.6 > 2010-02-03 09:44:53,361 INFO org.apache.zookeeper.server.ZooKeeperServer: > Server environment:user.name=zaharije > 2010-02-03 09:44:53,361 INFO org.apache.zookeeper.server.ZooKeeperServer: > Server environment:user.home=/Users/zaharije > 2010-02-03 09:44:53,361 INFO org.apache.zookeeper.server.ZooKeeperServer: > Server environment:user.dir=/usr/lib/hbase-0.20.3 > 2010-02-03 09:44:53,418 INFO > org.apache.zookeeper.server.persistence.FileSnap: Reading snapshot > /tmp/hbase-zaharije/zookeeper/version-2/snapshot.fd > 2010-02-03 09:44:53,458 INFO > org.apache.zookeeper.server.persistence.FileTxnSnapLog: Snapshotting: 119 > 2010-02-03 09:44:53,857 INFO org.apache.zookeeper.server.NIOServerCnxn: > Connected to /fe80:0:0:0:0:0:0:1%1:60769 lastZxid 0 > 2010-02-03 09:44:53,859 INFO org.apache.zookeeper.server.NIOServerCnxn: > Creating new session 0x1269300e1560000 > 2010-02-03 09:44:53,890 INFO org.apache.zookeeper.server.NIOServerCnxn: > Finished init of 0x1269300e1560000 valid:true > 2010-02-03 09:44:53,905 WARN > org.apache.zookeeper.server.PrepRequestProcessor: Got exception when > processing sessionid:0x1269300e1560000 type:create cxid:0x4 > zxid:0xfffffffffffffffe txntype:unknown n/a > org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = > NodeExists > at > > org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcessor.java:245) > at > > org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:114) > 2010-02-03 09:44:53,910 WARN > org.apache.zookeeper.server.PrepRequestProcessor: Got exception when > processing sessionid:0x1269300e1560000 type:create cxid:0x6 > zxid:0xfffffffffffffffe txntype:unknown n/a > org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = > NodeExists > at > > org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcessor.java:245) > at > > org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:114) > 2010-02-03 09:44:53,961 INFO org.apache.zookeeper.server.NIOServerCnxn: > Connected to /0:0:0:0:0:0:0:1%0:60771 lastZxid 0 > 2010-02-03 09:44:53,961 INFO org.apache.zookeeper.server.NIOServerCnxn: > Creating new session 0x1269300e1560001 > 2010-02-03 09:44:53,962 INFO org.apache.zookeeper.server.NIOServerCnxn: > Finished init of 0x1269300e1560001 valid:true > 2010-02-03 09:44:54,777 WARN > org.apache.zookeeper.server.PrepRequestProcessor: Got exception when > processing sessionid:0x1269300e1560001 type:create cxid:0x3 > zxid:0xfffffffffffffffe txntype:unknown n/a > org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = > NodeExists > at > > org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcessor.java:245) > at > > org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:114) > 2010-02-03 09:44:55,099 WARN > org.apache.zookeeper.server.PrepRequestProcessor: Got exception when > processing sessionid:0x1269300e1560001 type:create cxid:0x6 > zxid:0xfffffffffffffffe txntype:unknown n/a > org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = > NodeExists > at > > org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcessor.java:245) > at > > org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:114) > 2010-02-03 09:44:56,104 WARN > org.apache.zookeeper.server.PrepRequestProcessor: Got exception when > processing sessionid:0x1269300e1560000 type:create cxid:0xe > zxid:0xfffffffffffffffe txntype:unknown n/a > org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = > NodeExists > at > > org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcessor.java:245) > at > > org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:114) > 2010-02-03 09:44:56,108 WARN > org.apache.zookeeper.server.PrepRequestProcessor: Got exception when > processing sessionid:0x1269300e1560000 type:create cxid:0x10 > zxid:0xfffffffffffffffe txntype:unknown n/a > org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = > NodeExists > at > > org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcessor.java:245) > at > > org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:114) > 2010-02-03 09:46:25,767 INFO org.apache.zookeeper.server.NIOServerCnxn: > Connected to /fe80:0:0:0:0:0:0:1%1:60781 lastZxid 0 > 2010-02-03 09:46:25,768 INFO org.apache.zookeeper.server.NIOServerCnxn: > Creating new session 0x1269300e1560002 > 2010-02-03 09:46:25,769 INFO org.apache.zookeeper.server.NIOServerCnxn: > Finished init of 0x1269300e1560002 valid:true > 2010-02-03 09:46:25,882 WARN > org.apache.zookeeper.server.PrepRequestProcessor: Got exception when > processing sessionid:0x1269300e1560002 type:create cxid:0x2 > zxid:0xfffffffffffffffe txntype:unknown n/a > org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = > NodeExists > at > > org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcessor.java:245) > at > > org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:114) > 2010-02-03 09:46:26,014 INFO > org.apache.zookeeper.server.PrepRequestProcessor: Processed session > termination request for id: 0x1269300e1560002 > 2010-02-03 09:46:26,015 INFO org.apache.zookeeper.server.NIOServerCnxn: > closing session:0x1269300e1560002 NIOServerCnxn: > java.nio.channels.SocketChannel[connected local=/fe80:0:0:0:0:0:0:1%1:2181 > remote=/fe80:0:0:0:0:0:0:1%1:60781] > > > -------------------------------------------------------------------------------------------- > > Here is hbase master's log: > > Wed Feb 3 09:44:51 CET 2010 Starting master on hari-mac.local > ulimit -n 256 > 2010-02-03 09:44:52,103 INFO org.apache.hadoop.hbase.master.HMaster: > vmName=Java HotSpot(TM) 64-Bit Server VM, vmVendor=Apple Inc., > vmVersion=14.1-b02-90 > 2010-02-03 09:44:52,104 INFO org.apache.hadoop.hbase.master.HMaster: > vmInputArguments=[-Xmx1000m, -XX:+HeapDumpOnOutOfMemoryError, > -XX:+UseConcMarkSweepGC, -XX:+CMSIncrementalMode, > -Dhbase.log.dir=/usr/lib/hbase-0.20.3/logs, > -Dhbase.log.file=hbase-zaharije-master-hari-mac.local.log, > -Dhbase.home.dir=/usr/lib/hbase-0.20.3, -Dhbase.id.str=zaharije, > -Dhbase.root.logger=INFO,DRFA, > -Djava.library.path=/usr/lib/hbase-0.20.3/lib/native/Mac_OS_X-x86_64-64] > 2010-02-03 09:44:52,164 INFO org.apache.hadoop.hbase.master.HMaster: My > address is 192.168.0.2:60000 > 2010-02-03 09:44:52,366 INFO org.apache.hadoop.hbase.ipc.HBaseRpcMetrics: > Initializing RPC Metrics with hostName=HMaster, port=60000 > 2010-02-03 09:44:52,454 INFO org.apache.zookeeper.ZooKeeper: Client > environment:zookeeper.version=3.2.2-888565, built on 12/08/2009 21:51 GMT > 2010-02-03 09:44:52,454 INFO org.apache.zookeeper.ZooKeeper: Client > environment:host.name=192.168.0.2 > 2010-02-03 09:44:52,454 INFO org.apache.zookeeper.ZooKeeper: Client > environment:java.version=1.6.0_15 > 2010-02-03 09:44:52,454 INFO org.apache.zookeeper.ZooKeeper: Client > environment:java.vendor=Apple Inc. > 2010-02-03 09:44:52,454 INFO org.apache.zookeeper.ZooKeeper: Client > > environment:java.home=/System/Library/Frameworks/JavaVM.framework/Versions/1.6.0/Home > 2010-02-03 09:44:52,454 INFO org.apache.zookeeper.ZooKeeper: Client > > environment:java.class.path=/usr/lib/hbase-0.20.3/conf:/Library/Java/Home/lib/tools.jar:/usr/lib/hbase-0.20.3:/usr/lib/hbase-0.20.3/hbase-0.20.3-test.jar:/usr/lib/hbase-0.20.3/hbase-0.20.3.jar:/usr/lib/hbase-0.20.3/lib/AgileJSON-2009-03-30.jar:/usr/lib/hbase-0.20.3/lib/commons-cli-2.0-SNAPSHOT.jar:/usr/lib/hbase-0.20.3/lib/commons-el-from-jetty-5.1.4.jar:/usr/lib/hbase-0.20.3/lib/commons-httpclient-3.0.1.jar:/usr/lib/hbase-0.20.3/lib/commons-logging-1.0.4.jar:/usr/lib/hbase-0.20.3/lib/commons-logging-api-1.0.4.jar:/usr/lib/hbase-0.20.3/lib/commons-math-1.1.jar:/usr/lib/hbase-0.20.3/lib/hadoop-0.20.1-hdfs127-core.jar:/usr/lib/hbase-0.20.3/lib/hadoop-0.20.1-test.jar:/usr/lib/hbase-0.20.3/lib/jasper-compiler-5.5.12.jar:/usr/lib/hbase-0.20.3/lib/jasper-runtime-5.5.12.jar:/usr/lib/hbase-0.20.3/lib/jetty-6.1.14.jar:/usr/lib/hbase-0.20.3/lib/jetty-util-6.1.14.jar:/usr/lib/hbase-0.20.3/lib/jruby-complete-1.2.0.jar:/usr/lib/hbase-0.20.3/lib/json.jar:/usr/lib/hbase-0.20.3/lib/junit-3.8.1.jar:/usr/lib/hbase-0.20.3/lib/libthrift-r771587.jar:/usr/lib/hbase-0.20.3/lib/log4j-1.2.15.jar:/usr/lib/hbase-0.20.3/lib/lucene-core-2.2.0.jar:/usr/lib/hbase-0.20.3/lib/servlet-api-2.5-6.1.14.jar:/usr/lib/hbase-0.20.3/lib/xmlenc-0.52.jar:/usr/lib/hbase-0.20.3/lib/zookeeper-3.2.2.jar:/usr/lib/hbase-0.20.3/lib/jsp-2.1/jsp-2.1.jar:/usr/lib/hbase-0.20.3/lib/jsp-2.1/jsp-api-2.1.jar > 2010-02-03 09:44:52,454 INFO org.apache.zookeeper.ZooKeeper: Client > > environment:java.library.path=/usr/lib/hbase-0.20.3/lib/native/Mac_OS_X-x86_64-64 > 2010-02-03 09:44:52,454 INFO org.apache.zookeeper.ZooKeeper: Client > > environment:java.io.tmpdir=/var/folders/bZ/bZ9NjEt6EEOL8obSel2K0E+++TI/-Tmp-/ > 2010-02-03 09:44:52,454 INFO org.apache.zookeeper.ZooKeeper: Client > environment:java.compiler=<NA> > 2010-02-03 09:44:52,454 INFO org.apache.zookeeper.ZooKeeper: Client > environment:os.name=Mac OS X > 2010-02-03 09:44:52,454 INFO org.apache.zookeeper.ZooKeeper: Client > environment:os.arch=x86_64 > 2010-02-03 09:44:52,454 INFO org.apache.zookeeper.ZooKeeper: Client > environment:os.version=10.6 > 2010-02-03 09:44:52,454 INFO org.apache.zookeeper.ZooKeeper: Client > environment:user.name=zaharije > 2010-02-03 09:44:52,455 INFO org.apache.zookeeper.ZooKeeper: Client > environment:user.home=/Users/zaharije > 2010-02-03 09:44:52,455 INFO org.apache.zookeeper.ZooKeeper: Client > environment:user.dir=/usr/lib/hbase-0.20.3/logs > 2010-02-03 09:44:52,456 INFO org.apache.zookeeper.ZooKeeper: Initiating > client connection, connectString=localhost:2181 sessionTimeout=60000 > watcher=Thread[Thread-1,5,main] > 2010-02-03 09:44:52,460 INFO org.apache.zookeeper.ClientCnxn: > zookeeper.disableAutoWatchReset is false > 2010-02-03 09:44:52,473 INFO org.apache.zookeeper.ClientCnxn: Attempting > connection to server localhost/0:0:0:0:0:0:0:1:2181 > 2010-02-03 09:44:52,477 WARN org.apache.zookeeper.ClientCnxn: Exception > closing session 0x0 to sun.nio.ch.selectionkeyi...@286e4365 > java.net.ConnectException: Connection refused > at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) > at > sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574) > at > org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:933) > 2010-02-03 09:44:52,479 WARN org.apache.zookeeper.ClientCnxn: Ignoring > exception during shutdown input > java.nio.channels.ClosedChannelException > at > sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638) > at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360) > at > org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:999) > at > org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:970) > 2010-02-03 09:44:52,479 WARN org.apache.zookeeper.ClientCnxn: Ignoring > exception during shutdown output > java.nio.channels.ClosedChannelException > at > sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649) > at sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368) > at > org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:1004) > at > org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:970) > 2010-02-03 09:44:52,495 INFO org.apache.hadoop.hbase.master.RegionManager: > -ROOT- region unset (but not set to be reassigned) > 2010-02-03 09:44:52,500 INFO org.apache.hadoop.hbase.master.RegionManager: > ROOT inserted into regionsInTransition > 2010-02-03 09:44:52,601 DEBUG > org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Failed to read: > org.apache.zookeeper.KeeperException$ConnectionLossException: > KeeperErrorCode = ConnectionLoss for /hbase/master > 2010-02-03 09:44:53,044 INFO org.apache.zookeeper.ClientCnxn: Attempting > connection to server localhost/127.0.0.1:2181 > 2010-02-03 09:44:53,045 WARN org.apache.zookeeper.ClientCnxn: Exception > closing session 0x0 to sun.nio.ch.selectionkeyi...@3a747fa2 > java.net.ConnectException: Connection refused > at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) > at > sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574) > at > org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:933) > 2010-02-03 09:44:53,046 WARN org.apache.zookeeper.ClientCnxn: Ignoring > exception during shutdown input > java.nio.channels.ClosedChannelException > at > sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:638) > at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360) > at > org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:999) > at > org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:970) > 2010-02-03 09:44:53,046 WARN org.apache.zookeeper.ClientCnxn: Ignoring > exception during shutdown output > java.nio.channels.ClosedChannelException > at > sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:649) > at sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:368) > at > org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:1004) > at > org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:970) > 2010-02-03 09:44:53,157 WARN > org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Failed to create /hbase > -- check quorum servers, currently=localhost:2181 > org.apache.zookeeper.KeeperException$ConnectionLossException: > KeeperErrorCode = ConnectionLoss for /hbase > at > org.apache.zookeeper.KeeperException.create(KeeperException.java:90) > at > org.apache.zookeeper.KeeperException.create(KeeperException.java:42) > at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:608) > at > > org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper.ensureExists(ZooKeeperWrapper.java:405) > at > > org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper.ensureParentExists(ZooKeeperWrapper.java:428) > at > > org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper.writeMasterAddress(ZooKeeperWrapper.java:516) > at > > org.apache.hadoop.hbase.master.HMaster.writeAddressToZooKeeper(HMaster.java:263) > at org.apache.hadoop.hbase.master.HMaster.<init>(HMaster.java:245) > at > org.apache.hadoop.hbase.LocalHBaseCluster.<init>(LocalHBaseCluster.java:94) > at > org.apache.hadoop.hbase.LocalHBaseCluster.<init>(LocalHBaseCluster.java:78) > at org.apache.hadoop.hbase.master.HMaster.doMain(HMaster.java:1237) > at org.apache.hadoop.hbase.master.HMaster.main(HMaster.java:1282) > 2010-02-03 09:44:53,846 INFO org.apache.zookeeper.ClientCnxn: Attempting > connection to server localhost/fe80:0:0:0:0:0:0:1%1:2181 > 2010-02-03 09:44:53,847 INFO org.apache.zookeeper.ClientCnxn: Priming > connection to java.nio.channels.SocketChannel[connected > local=/fe80:0:0:0:0:0:0:1%1:60769 > remote=localhost/fe80:0:0:0:0:0:0:1%1:2181] > 2010-02-03 09:44:53,849 INFO org.apache.zookeeper.ClientCnxn: Server > connection successful > 2010-02-03 09:44:53,898 DEBUG org.apache.hadoop.hbase.master.HMaster: Got > event None with path null > 2010-02-03 09:44:53,899 DEBUG > org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Failed to read: > org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = > NoNode for /hbase/master > 2010-02-03 09:44:53,909 DEBUG > org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Wrote master address > 192.168.0.2:60000 to ZooKeeper > 2010-02-03 09:44:53,912 DEBUG > org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: State node wrote in > ZooKeeper > 2010-02-03 09:44:53,920 DEBUG > org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Read ZNode > /hbase/master > got 192.168.0.2:60000 > 2010-02-03 09:44:53,920 INFO org.apache.hadoop.hbase.master.HMaster: > HMaster > initialized on 192.168.0.2:60000 > 2010-02-03 09:44:53,942 INFO > org.apache.hadoop.hbase.regionserver.HRegionServer: My address is > 192.168.0.2:0 > 2010-02-03 09:44:53,945 INFO org.apache.hadoop.hbase.ipc.HBaseRpcMetrics: > Initializing RPC Metrics with hostName=HRegionServer, port=60770 > 2010-02-03 09:44:53,948 INFO > org.apache.hadoop.hbase.regionserver.MemStoreFlusher: > globalMemStoreLimit=397.9m, globalMemStoreLimitLowMark=348.2m, > maxHeap=994.8m > 2010-02-03 09:44:53,950 INFO > org.apache.hadoop.hbase.regionserver.HRegionServer: Runs every 10000000ms > 2010-02-03 09:44:53,952 INFO org.apache.zookeeper.ZooKeeper: Initiating > client connection, connectString=localhost:2181 sessionTimeout=60000 > watcher=org.apache.hadoop.hbase.regionserver.hregionser...@48ff4cf > 2010-02-03 09:44:53,952 INFO org.apache.zookeeper.ClientCnxn: Attempting > connection to server localhost/0:0:0:0:0:0:0:1:2181 > 2010-02-03 09:44:53,960 INFO org.apache.zookeeper.ClientCnxn: Priming > connection to java.nio.channels.SocketChannel[connected > local=/0:0:0:0:0:0:0:1%0:60771 remote=localhost/0:0:0:0:0:0:0:1:2181] > 2010-02-03 09:44:53,960 INFO org.apache.zookeeper.ClientCnxn: Server > connection successful > 2010-02-03 09:44:53,963 INFO > org.apache.hadoop.hbase.regionserver.HRegionServer: Got ZooKeeper event, > state: SyncConnected, type: None, path: null > 2010-02-03 09:44:53,964 DEBUG > org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Set watcher on master > address ZNode /hbase/master > 2010-02-03 09:44:54,016 DEBUG org.apache.hadoop.hbase.master.HMaster: > Checking cluster state... > 2010-02-03 09:44:54,017 DEBUG > org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Read ZNode > /hbase/root-region-server got 192.168.0.2:60604 > 2010-02-03 09:44:54,017 DEBUG > org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Read ZNode > /hbase/master > got 192.168.0.2:60000 > 2010-02-03 09:44:54,017 INFO > org.apache.hadoop.hbase.regionserver.HRegionServer: Telling master at > 192.168.0.2:60000 that we are up > 2010-02-03 09:44:54,022 DEBUG org.apache.hadoop.hbase.master.HMaster: This > is a fresh start, proceeding with normal startup > 2010-02-03 09:44:54,022 DEBUG org.apache.hadoop.hbase.master.HMaster: No > log > files to split, proceeding... > 2010-02-03 09:44:54,025 INFO org.apache.hadoop.metrics.jvm.JvmMetrics: > Initializing JVM Metrics with processName=Master, sessionId=HMaster > 2010-02-03 09:44:54,026 INFO > org.apache.hadoop.hbase.master.metrics.MasterMetrics: Initialized > 2010-02-03 09:44:54,188 INFO org.apache.hadoop.http.HttpServer: Port > returned by webServer.getConnectors()[0].getLocalPort() before open() is > -1. > Opening the listener on 60010 > 2010-02-03 09:44:54,188 INFO org.apache.hadoop.http.HttpServer: > listener.getLocalPort() returned 60010 > webServer.getConnectors()[0].getLocalPort() returned 60010 > 2010-02-03 09:44:54,188 INFO org.apache.hadoop.http.HttpServer: Jetty bound > to port 60010 > 2010-02-03 09:44:54,755 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > Responder: starting > 2010-02-03 09:44:54,756 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > listener on 60000: starting > 2010-02-03 09:44:54,760 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 0 on 60000: starting > 2010-02-03 09:44:54,764 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 1 on 60000: starting > 2010-02-03 09:44:54,764 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 2 on 60000: starting > 2010-02-03 09:44:54,764 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 3 on 60000: starting > 2010-02-03 09:44:54,764 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 4 on 60000: starting > 2010-02-03 09:44:54,765 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 5 on 60000: starting > 2010-02-03 09:44:54,765 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 6 on 60000: starting > 2010-02-03 09:44:54,765 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 7 on 60000: starting > 2010-02-03 09:44:54,765 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 8 on 60000: starting > 2010-02-03 09:44:54,773 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 9 on 60000: starting > 2010-02-03 09:44:54,773 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 24 on 60000: starting > 2010-02-03 09:44:54,773 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 23 on 60000: starting > 2010-02-03 09:44:54,773 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 22 on 60000: starting > 2010-02-03 09:44:54,773 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 21 on 60000: starting > 2010-02-03 09:44:54,773 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 20 on 60000: starting > 2010-02-03 09:44:54,773 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 19 on 60000: starting > 2010-02-03 09:44:54,774 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 18 on 60000: starting > 2010-02-03 09:44:54,774 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 17 on 60000: starting > 2010-02-03 09:44:54,774 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 16 on 60000: starting > 2010-02-03 09:44:54,774 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 15 on 60000: starting > 2010-02-03 09:44:54,774 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 14 on 60000: starting > 2010-02-03 09:44:54,774 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 13 on 60000: starting > 2010-02-03 09:44:54,774 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 12 on 60000: starting > 2010-02-03 09:44:54,774 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 11 on 60000: starting > 2010-02-03 09:44:54,774 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 10 on 60000: starting > 2010-02-03 09:44:54,774 DEBUG org.apache.hadoop.hbase.master.HMaster: > Started service threads > 2010-02-03 09:44:54,775 DEBUG > org.apache.hadoop.hbase.regionserver.HRegionServer: sending initial server > load: requests=0, regions=0, usedHeap=31, maxHeap=994 > 2010-02-03 09:44:54,780 DEBUG > org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Created ZNode > /hbase/rs/1265186694776 with data 192.168.0.2:60770 > 2010-02-03 09:44:54,782 INFO org.apache.hadoop.hbase.master.ServerManager: > Received start message from: 192.168.0.2,60770,1265186694776 > 2010-02-03 09:44:54,786 DEBUG > org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Updated ZNode > /hbase/rs/1265186694776 with data 192.168.0.2:60770 > 2010-02-03 09:44:54,793 DEBUG > org.apache.hadoop.hbase.regionserver.HRegionServer: Config from master: > hbase.regionserver.address=192.168.0.2 > 2010-02-03 09:44:54,793 DEBUG > org.apache.hadoop.hbase.regionserver.HRegionServer: Config from master: > fs.default.name=file:/tmp/hbase-zaharije/hbase > 2010-02-03 09:44:54,793 DEBUG > org.apache.hadoop.hbase.regionserver.HRegionServer: Config from master: > hbase.rootdir=file:/tmp/hbase-zaharije/hbase > 2010-02-03 09:44:54,793 INFO > org.apache.hadoop.hbase.regionserver.HRegionServer: Master passed us > address > to use. Was=192.168.0.2:60770, Now=192.168.0.2 > 2010-02-03 09:44:54,797 DEBUG > org.apache.hadoop.hbase.regionserver.HRegionServer: Log dir > file:/tmp/hbase-zaharije/hbase/.logs/192.168.0.2,60770,1265186694776 > 2010-02-03 09:44:54,798 INFO org.apache.hadoop.hbase.regionserver.HLog: > HLog > configuration: blocksize=33554432, rollsize=31876710, enabled=true, > flushlogentries=100, optionallogflushinternal=10000ms > 2010-02-03 09:44:54,839 INFO org.apache.hadoop.hbase.regionserver.HLog: New > hlog > /tmp/hbase-zaharije/hbase/.logs/192.168.0.2 > ,60770,1265186694776/hlog.dat.1265186694798 > 2010-02-03 09:44:54,841 INFO org.apache.hadoop.metrics.jvm.JvmMetrics: > Cannot initialize JVM Metrics with processName=RegionServer, > sessionId=RegionServer:0 - already initialized > 2010-02-03 09:44:54,843 INFO > org.apache.hadoop.hbase.regionserver.metrics.RegionServerMetrics: > Initialized > 2010-02-03 09:44:54,870 INFO org.apache.hadoop.http.HttpServer: Port > returned by webServer.getConnectors()[0].getLocalPort() before open() is > -1. > Opening the listener on 60030 > 2010-02-03 09:44:54,870 INFO org.apache.hadoop.http.HttpServer: > listener.getLocalPort() returned 60030 > webServer.getConnectors()[0].getLocalPort() returned 60030 > 2010-02-03 09:44:54,870 INFO org.apache.hadoop.http.HttpServer: Jetty bound > to port 60030 > 2010-02-03 09:44:55,070 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > Responder: starting > 2010-02-03 09:44:55,071 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > listener on 60770: starting > 2010-02-03 09:44:55,071 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 0 on 60770: starting > 2010-02-03 09:44:55,071 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 1 on 60770: starting > 2010-02-03 09:44:55,072 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 2 on 60770: starting > 2010-02-03 09:44:55,072 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 3 on 60770: starting > 2010-02-03 09:44:55,072 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 4 on 60770: starting > 2010-02-03 09:44:55,072 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 5 on 60770: starting > 2010-02-03 09:44:55,073 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 6 on 60770: starting > 2010-02-03 09:44:55,073 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 7 on 60770: starting > 2010-02-03 09:44:55,073 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 8 on 60770: starting > 2010-02-03 09:44:55,073 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 9 on 60770: starting > 2010-02-03 09:44:55,074 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 10 on 60770: starting > 2010-02-03 09:44:55,074 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 11 on 60770: starting > 2010-02-03 09:44:55,074 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 12 on 60770: starting > 2010-02-03 09:44:55,074 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 13 on 60770: starting > 2010-02-03 09:44:55,074 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 14 on 60770: starting > 2010-02-03 09:44:55,075 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 15 on 60770: starting > 2010-02-03 09:44:55,075 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 16 on 60770: starting > 2010-02-03 09:44:55,075 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 17 on 60770: starting > 2010-02-03 09:44:55,076 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 18 on 60770: starting > 2010-02-03 09:44:55,077 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 19 on 60770: starting > 2010-02-03 09:44:55,077 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 20 on 60770: starting > 2010-02-03 09:44:55,077 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 21 on 60770: starting > 2010-02-03 09:44:55,078 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 22 on 60770: starting > 2010-02-03 09:44:55,078 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 23 on 60770: starting > 2010-02-03 09:44:55,078 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server > handler 24 on 60770: starting > 2010-02-03 09:44:55,078 INFO > org.apache.hadoop.hbase.regionserver.HRegionServer: HRegionServer started > at: 192.168.0.2:60770 > 2010-02-03 09:44:55,080 DEBUG > org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Read ZNode > /hbase/root-region-server got 192.168.0.2:60604 > 2010-02-03 09:44:55,085 INFO > org.apache.hadoop.hbase.regionserver.StoreFile: > Allocating LruBlockCache with maximum size 199.0m > 2010-02-03 09:44:55,096 INFO org.apache.hadoop.hbase.master.RegionManager: > Assigning region -ROOT-,,0 to 192.168.0.2,60770,1265186694776 > 2010-02-03 09:44:55,098 INFO > org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN: > -ROOT-,,0 > 2010-02-03 09:44:55,102 INFO > org.apache.hadoop.hbase.regionserver.HRegionServer: Worker: > MSG_REGION_OPEN: > -ROOT-,,0 > 2010-02-03 09:44:55,107 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: > Opening region -ROOT-,,0, encoded=70236052 > 2010-02-03 09:44:55,131 DEBUG org.apache.hadoop.hbase.regionserver.Store: > loaded /tmp/hbase-zaharije/hbase/-ROOT-/70236052/info/4121684240873727880, > isReference=false, sequence id=2, length=841, majorCompaction=false > 2010-02-03 09:44:55,141 DEBUG org.apache.hadoop.hbase.regionserver.Store: > loaded /tmp/hbase-zaharije/hbase/-ROOT-/70236052/info/8103669253369757722, > isReference=false, sequence id=10, length=460, majorCompaction=false > 2010-02-03 09:44:55,142 INFO org.apache.hadoop.hbase.regionserver.HRegion: > region -ROOT-,,0/70236052 available; sequence id is 11 > 2010-02-03 09:44:56,102 INFO org.apache.hadoop.hbase.master.ServerManager: > Processing MSG_REPORT_OPEN: -ROOT-,,0 from 192.168.0.2,60770,1265186694776; > 1 of 1 > 2010-02-03 09:44:56,107 WARN > org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Failed to create out of > safe mode in ZooKeeper: > org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = > NodeExists for /hbase/safe-mode > 2010-02-03 09:44:56,107 INFO > org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Node exists; just move > on > 2010-02-03 09:44:56,107 INFO org.apache.hadoop.hbase.master.RegionManager: > exiting safe mode > 2010-02-03 09:44:56,111 DEBUG > org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: SetData of ZNode > /hbase/root-region-server with 192.168.0.2:60770 > 2010-02-03 09:44:56,112 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.rootScanner scanning meta region {server: 192.168.0.2:60770, > regionname: -ROOT-,,0, startKey: <>} > 2010-02-03 09:44:56,166 DEBUG org.apache.hadoop.hbase.master.BaseScanner: > Current assignment of .META.,,1 is not valid; > serverAddress=192.168.0.2:60604, startCode=1265185588724 unknown. > 2010-02-03 09:44:56,167 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.rootScanner scan of 1 row(s) of meta region {server: > 192.168.0.2:60770, regionname: -ROOT-,,0, startKey: <>} complete > 2010-02-03 09:44:57,116 INFO org.apache.hadoop.hbase.master.RegionManager: > Assigning region .META.,,1 to 192.168.0.2,60770,1265186694776 > 2010-02-03 09:44:57,117 INFO > org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN: > .META.,,1 > 2010-02-03 09:44:57,117 INFO > org.apache.hadoop.hbase.regionserver.HRegionServer: Worker: > MSG_REGION_OPEN: > .META.,,1 > 2010-02-03 09:44:57,117 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: > Opening region .META.,,1, encoded=1028785192 > 2010-02-03 09:44:57,122 DEBUG org.apache.hadoop.hbase.regionserver.Store: > loaded > /tmp/hbase-zaharije/hbase/.META./1028785192/info/7248722017355517707, > isReference=false, sequence id=9, length=978, majorCompaction=false > 2010-02-03 09:44:57,122 INFO org.apache.hadoop.hbase.regionserver.HRegion: > region .META.,,1/1028785192 available; sequence id is 10 > 2010-02-03 09:44:58,120 INFO org.apache.hadoop.hbase.master.ServerManager: > Processing MSG_REPORT_PROCESS_OPEN: .META.,,1 from > 192.168.0.2,60770,1265186694776; 1 of 2 > 2010-02-03 09:44:58,121 INFO org.apache.hadoop.hbase.master.ServerManager: > Processing MSG_REPORT_OPEN: .META.,,1 from 192.168.0.2,60770,1265186694776; > 2 of 2 > 2010-02-03 09:44:58,124 DEBUG org.apache.hadoop.hbase.master.HMaster: > Processing todo: PendingOpenOperation from 192.168.0.2,60770,1265186694776 > 2010-02-03 09:44:58,124 INFO > org.apache.hadoop.hbase.master.RegionServerOperation: .META.,,1 open on > 192.168.0.2:60770 > 2010-02-03 09:44:58,127 INFO > org.apache.hadoop.hbase.master.RegionServerOperation: Updated row .META.,,1 > in region -ROOT-,,0 with startcode=1265186694776, server=192.168.0.2:60770 > 2010-02-03 09:44:58,128 DEBUG > org.apache.hadoop.hbase.master.RegionServerOperation: Adding to > onlineMetaRegions: {server: 192.168.0.2:60770, regionname: .META.,,1, > startKey: <>} > 2010-02-03 09:45:52,488 INFO org.apache.hadoop.hbase.master.ServerManager: > 1 > region servers, 0 dead, average load 2.0 > 2010-02-03 09:45:54,027 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.rootScanner scanning meta region {server: 192.168.0.2:60770, > regionname: -ROOT-,,0, startKey: <>} > 2010-02-03 09:45:54,029 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.metaScanner scanning meta region {server: 192.168.0.2:60770, > regionname: .META.,,1, startKey: <>} > 2010-02-03 09:45:54,049 DEBUG org.apache.hadoop.hbase.master.BaseScanner: > Current assignment of test,,1265185608929 is not valid; > serverAddress=192.168.0.2:60604, startCode=1265185588724 unknown. > 2010-02-03 09:45:54,050 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.metaScanner scan of 1 row(s) of meta region {server: > 192.168.0.2:60770, regionname: .META.,,1, startKey: <>} complete > 2010-02-03 09:45:54,050 INFO org.apache.hadoop.hbase.master.BaseScanner: > All > 1 .META. region(s) scanned > 2010-02-03 09:45:54,051 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.rootScanner scan of 1 row(s) of meta region {server: > 192.168.0.2:60770, regionname: -ROOT-,,0, startKey: <>} complete > 2010-02-03 09:45:54,320 INFO org.apache.hadoop.hbase.master.RegionManager: > Assigning region test,,1265185608929 to 192.168.0.2,60770,1265186694776 > 2010-02-03 09:45:54,321 INFO > org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN: > test,,1265185608929 > 2010-02-03 09:45:54,321 INFO > org.apache.hadoop.hbase.regionserver.HRegionServer: Worker: > MSG_REGION_OPEN: > test,,1265185608929 > 2010-02-03 09:45:54,322 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: > Opening region test,,1265185608929, encoded=956999107 > 2010-02-03 09:45:54,325 INFO org.apache.hadoop.hbase.regionserver.HRegion: > region test,,1265185608929/956999107 available; sequence id is 0 > 2010-02-03 09:45:55,093 DEBUG > org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes: > Total=1.6344376MB (1713832), Free=197.32806MB (206913480), Max=198.96251MB > (208627312), Counts: Blocks=2, Access=8, Hit=6, Miss=2, Evictions=0, > Evicted=0, Ratios: Hit Ratio=75.0%, Miss Ratio=25.0%, Evicted/Run=NaN > 2010-02-03 09:45:55,325 INFO org.apache.hadoop.hbase.master.ServerManager: > Processing MSG_REPORT_PROCESS_OPEN: test,,1265185608929 from > 192.168.0.2,60770,1265186694776; 1 of 2 > 2010-02-03 09:45:55,325 INFO org.apache.hadoop.hbase.master.ServerManager: > Processing MSG_REPORT_OPEN: test,,1265185608929 from > 192.168.0.2,60770,1265186694776; 2 of 2 > 2010-02-03 09:45:55,326 DEBUG org.apache.hadoop.hbase.master.HMaster: > Processing todo: PendingOpenOperation from 192.168.0.2,60770,1265186694776 > 2010-02-03 09:45:55,326 INFO > org.apache.hadoop.hbase.master.RegionServerOperation: test,,1265185608929 > open on 192.168.0.2:60770 > 2010-02-03 09:45:55,327 INFO > org.apache.hadoop.hbase.master.RegionServerOperation: Updated row > test,,1265185608929 in region .META.,,1 with startcode=1265186694776, > server=192.168.0.2:60770 > 2010-02-03 09:46:52,487 INFO org.apache.hadoop.hbase.master.ServerManager: > 1 > region servers, 0 dead, average load 3.0 > 2010-02-03 09:46:54,027 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.rootScanner scanning meta region {server: 192.168.0.2:60770, > regionname: -ROOT-,,0, startKey: <>} > 2010-02-03 09:46:54,030 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.metaScanner scanning meta region {server: 192.168.0.2:60770, > regionname: .META.,,1, startKey: <>} > 2010-02-03 09:46:54,040 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.rootScanner scan of 1 row(s) of meta region {server: > 192.168.0.2:60770, regionname: -ROOT-,,0, startKey: <>} complete > 2010-02-03 09:46:54,040 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.metaScanner scan of 1 row(s) of meta region {server: > 192.168.0.2:60770, regionname: .META.,,1, startKey: <>} complete > 2010-02-03 09:46:54,040 INFO org.apache.hadoop.hbase.master.BaseScanner: > All > 1 .META. region(s) scanned > 2010-02-03 09:46:55,092 DEBUG > org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes: > Total=1.6344376MB (1713832), Free=197.32806MB (206913480), Max=198.96251MB > (208627312), Counts: Blocks=2, Access=16, Hit=14, Miss=2, Evictions=0, > Evicted=0, Ratios: Hit Ratio=87.5%, Miss Ratio=12.5%, Evicted/Run=NaN > 2010-02-03 09:47:52,487 INFO org.apache.hadoop.hbase.master.ServerManager: > 1 > region servers, 0 dead, average load 3.0 > 2010-02-03 09:47:54,028 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.rootScanner scanning meta region {server: 192.168.0.2:60770, > regionname: -ROOT-,,0, startKey: <>} > 2010-02-03 09:47:54,030 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.metaScanner scanning meta region {server: 192.168.0.2:60770, > regionname: .META.,,1, startKey: <>} > 2010-02-03 09:47:54,043 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.rootScanner scan of 1 row(s) of meta region {server: > 192.168.0.2:60770, regionname: -ROOT-,,0, startKey: <>} complete > 2010-02-03 09:47:54,044 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.metaScanner scan of 1 row(s) of meta region {server: > 192.168.0.2:60770, regionname: .META.,,1, startKey: <>} complete > 2010-02-03 09:47:54,044 INFO org.apache.hadoop.hbase.master.BaseScanner: > All > 1 .META. region(s) scanned > 2010-02-03 09:47:55,092 DEBUG > org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes: > Total=1.6344376MB (1713832), Free=197.32806MB (206913480), Max=198.96251MB > (208627312), Counts: Blocks=2, Access=20, Hit=18, Miss=2, Evictions=0, > Evicted=0, Ratios: Hit Ratio=89.99999761581421%, Miss > Ratio=10.000000149011612%, Evicted/Run=NaN > 2010-02-03 09:48:52,487 INFO org.apache.hadoop.hbase.master.ServerManager: > 1 > region servers, 0 dead, average load 3.0 > 2010-02-03 09:48:54,028 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.rootScanner scanning meta region {server: 192.168.0.2:60770, > regionname: -ROOT-,,0, startKey: <>} > 2010-02-03 09:48:54,030 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.metaScanner scanning meta region {server: 192.168.0.2:60770, > regionname: .META.,,1, startKey: <>} > 2010-02-03 09:48:54,057 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.rootScanner scan of 1 row(s) of meta region {server: > 192.168.0.2:60770, regionname: -ROOT-,,0, startKey: <>} complete > 2010-02-03 09:48:54,057 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.metaScanner scan of 1 row(s) of meta region {server: > 192.168.0.2:60770, regionname: .META.,,1, startKey: <>} complete > 2010-02-03 09:48:54,057 INFO org.apache.hadoop.hbase.master.BaseScanner: > All > 1 .META. region(s) scanned > 2010-02-03 09:48:55,092 DEBUG > org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes: > Total=1.6344376MB (1713832), Free=197.32806MB (206913480), Max=198.96251MB > (208627312), Counts: Blocks=2, Access=24, Hit=22, Miss=2, Evictions=0, > Evicted=0, Ratios: Hit Ratio=91.66666865348816%, Miss > Ratio=8.33333358168602%, Evicted/Run=NaN > 2010-02-03 09:49:52,487 INFO org.apache.hadoop.hbase.master.ServerManager: > 1 > region servers, 0 dead, average load 3.0 > 2010-02-03 09:49:54,028 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.rootScanner scanning meta region {server: 192.168.0.2:60770, > regionname: -ROOT-,,0, startKey: <>} > 2010-02-03 09:49:54,032 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.metaScanner scanning meta region {server: 192.168.0.2:60770, > regionname: .META.,,1, startKey: <>} > 2010-02-03 09:49:54,044 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.rootScanner scan of 1 row(s) of meta region {server: > 192.168.0.2:60770, regionname: -ROOT-,,0, startKey: <>} complete > 2010-02-03 09:49:54,044 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.metaScanner scan of 1 row(s) of meta region {server: > 192.168.0.2:60770, regionname: .META.,,1, startKey: <>} complete > 2010-02-03 09:49:54,044 INFO org.apache.hadoop.hbase.master.BaseScanner: > All > 1 .META. region(s) scanned > 2010-02-03 09:49:55,092 DEBUG > org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes: > Total=1.6344376MB (1713832), Free=197.32806MB (206913480), Max=198.96251MB > (208627312), Counts: Blocks=2, Access=28, Hit=26, Miss=2, Evictions=0, > Evicted=0, Ratios: Hit Ratio=92.85714030265808%, Miss > Ratio=7.14285746216774%, Evicted/Run=NaN > 2010-02-03 09:50:52,487 INFO org.apache.hadoop.hbase.master.ServerManager: > 1 > region servers, 0 dead, average load 3.0 > 2010-02-03 09:50:54,028 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.rootScanner scanning meta region {server: 192.168.0.2:60770, > regionname: -ROOT-,,0, startKey: <>} > 2010-02-03 09:50:54,031 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.metaScanner scanning meta region {server: 192.168.0.2:60770, > regionname: .META.,,1, startKey: <>} > 2010-02-03 09:50:54,037 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.rootScanner scan of 1 row(s) of meta region {server: > 192.168.0.2:60770, regionname: -ROOT-,,0, startKey: <>} complete > 2010-02-03 09:50:54,037 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.metaScanner scan of 1 row(s) of meta region {server: > 192.168.0.2:60770, regionname: .META.,,1, startKey: <>} complete > 2010-02-03 09:50:54,037 INFO org.apache.hadoop.hbase.master.BaseScanner: > All > 1 .META. region(s) scanned > 2010-02-03 09:50:55,092 DEBUG > org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes: > Total=1.6344376MB (1713832), Free=197.32806MB (206913480), Max=198.96251MB > (208627312), Counts: Blocks=2, Access=32, Hit=30, Miss=2, Evictions=0, > Evicted=0, Ratios: Hit Ratio=93.75%, Miss Ratio=6.25%, Evicted/Run=NaN > 2010-02-03 09:51:52,487 INFO org.apache.hadoop.hbase.master.ServerManager: > 1 > region servers, 0 dead, average load 3.0 > 2010-02-03 09:51:54,028 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.rootScanner scanning meta region {server: 192.168.0.2:60770, > regionname: -ROOT-,,0, startKey: <>} > 2010-02-03 09:51:54,031 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.metaScanner scanning meta region {server: 192.168.0.2:60770, > regionname: .META.,,1, startKey: <>} > 2010-02-03 09:51:54,040 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.rootScanner scan of 1 row(s) of meta region {server: > 192.168.0.2:60770, regionname: -ROOT-,,0, startKey: <>} complete > 2010-02-03 09:51:54,041 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.metaScanner scan of 1 row(s) of meta region {server: > 192.168.0.2:60770, regionname: .META.,,1, startKey: <>} complete > 2010-02-03 09:51:54,041 INFO org.apache.hadoop.hbase.master.BaseScanner: > All > 1 .META. region(s) scanned > 2010-02-03 09:51:55,092 DEBUG > org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes: > Total=1.6344376MB (1713832), Free=197.32806MB (206913480), Max=198.96251MB > (208627312), Counts: Blocks=2, Access=36, Hit=34, Miss=2, Evictions=0, > Evicted=0, Ratios: Hit Ratio=94.44444179534912%, Miss > Ratio=5.55555559694767%, Evicted/Run=NaN > 2010-02-03 09:52:52,487 INFO org.apache.hadoop.hbase.master.ServerManager: > 1 > region servers, 0 dead, average load 3.0 > 2010-02-03 09:52:54,028 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.rootScanner scanning meta region {server: 192.168.0.2:60770, > regionname: -ROOT-,,0, startKey: <>} > 2010-02-03 09:52:54,032 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.metaScanner scanning meta region {server: 192.168.0.2:60770, > regionname: .META.,,1, startKey: <>} > 2010-02-03 09:52:54,044 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.rootScanner scan of 1 row(s) of meta region {server: > 192.168.0.2:60770, regionname: -ROOT-,,0, startKey: <>} complete > 2010-02-03 09:52:54,044 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.metaScanner scan of 1 row(s) of meta region {server: > 192.168.0.2:60770, regionname: .META.,,1, startKey: <>} complete > 2010-02-03 09:52:54,044 INFO org.apache.hadoop.hbase.master.BaseScanner: > All > 1 .META. region(s) scanned > 2010-02-03 09:52:55,092 DEBUG > org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes: > Total=1.6344376MB (1713832), Free=197.32806MB (206913480), Max=198.96251MB > (208627312), Counts: Blocks=2, Access=40, Hit=38, Miss=2, Evictions=0, > Evicted=0, Ratios: Hit Ratio=94.9999988079071%, Miss > Ratio=5.000000074505806%, Evicted/Run=NaN > 2010-02-03 09:53:52,487 INFO org.apache.hadoop.hbase.master.ServerManager: > 1 > region servers, 0 dead, average load 3.0 > 2010-02-03 09:53:54,029 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.rootScanner scanning meta region {server: 192.168.0.2:60770, > regionname: -ROOT-,,0, startKey: <>} > 2010-02-03 09:53:54,033 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.metaScanner scanning meta region {server: 192.168.0.2:60770, > regionname: .META.,,1, startKey: <>} > 2010-02-03 09:53:54,043 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.rootScanner scan of 1 row(s) of meta region {server: > 192.168.0.2:60770, regionname: -ROOT-,,0, startKey: <>} complete > 2010-02-03 09:53:54,043 INFO org.apache.hadoop.hbase.master.BaseScanner: > RegionManager.metaScanner scan of 1 row(s) of meta region {server: > 192.168.0.2:60770, regionname: .META.,,1, startKey: <>} complete > 2010-02-03 09:53:54,044 INFO org.apache.hadoop.hbase.master.BaseScanner: > All > 1 .META. region(s) scanned > 2010-02-03 09:53:55,092 DEBUG > org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes: > Total=1.6344376MB (1713832), Free=197.32806MB (206913480), Max=198.96251MB > (208627312), Counts: Blocks=2, Access=44, Hit=42, Miss=2, Evictions=0, > Evicted=0, Ratios: Hit Ratio=95.45454382896423%, Miss > Ratio=4.545454680919647%, Evicted/Run=NaN > > > -- > View this message in context: > http://old.nabble.com/Exception-trace-in-client-log-...-tp27433209p27433209.html > Sent from the HBase User mailing list archive at Nabble.com. > >