Have you checked region server log on server.epicoders.com,60020,1364559783898 around the time NotServingRegionException was seen in master log ?
What version of HBase are you using ? Thanks On Mon, Apr 1, 2013 at 9:20 PM, Praveen Bysani <[email protected]>wrote: > Hi, > > When i try to restart the HBase service i see the following errors in > my Hbase Master log, > > > 2013-04-02 03:37:29,713 INFO > org.apache.hadoop.hbase.master.metrics.MasterMetrics: Initialized > 2013-04-02 03:37:29,797 INFO > org.apache.hadoop.hbase.master.ActiveMasterManager: Deleting ZNode for > /hbase/backup-masters/server.epicoders.com,60000,1364873849167 from > backup master directory > 2013-04-02 03:37:29,816 WARN > org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper: Node > /hbase/backup-masters/server.epicoders.com,60000,1364873849167 already > deleted, and this is not a retry > 2013-04-02 03:37:29,816 INFO > org.apache.hadoop.hbase.master.ActiveMasterManager: > Master=server.epicoders.com,60000,1364873849167 > 2013-04-02 03:37:31,830 WARN org.apache.hadoop.conf.Configuration: > fs.default.name is deprecated. Instead, use fs.defaultFS > 2013-04-02 03:37:31,848 INFO > org.apache.hadoop.hbase.master.SplitLogManager: found 0 orphan tasks > and 0 rescan nodes > 2013-04-02 03:37:32,349 WARN org.apache.hadoop.conf.Configuration: > hadoop.native.lib is deprecated. Instead, use io.native.lib.available > 2013-04-02 03:37:32,774 INFO org.apache.hadoop.hbase.master.HMaster: > Server active/primary master; > server.epicoders.com,60000,1364873849167, sessionid=0x13daf9ed2b90086, > cluster-up flag was=false > 2013-04-02 03:37:32,817 INFO > org.apache.hadoop.hbase.master.snapshot.SnapshotManager: Snapshot > feature is not enabled, missing log and hfile cleaners. > 2013-04-02 03:37:32,846 INFO > org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper: Node > /hbase/online-snapshot/acquired already exists and this is not a retry > 2013-04-02 03:37:32,856 INFO > org.apache.hadoop.hbase.procedure.ZKProcedureUtil: Clearing all > procedure znodes: /hbase/online-snapshot/acquired > /hbase/online-snapshot/reached /hbase/online-snapshot/abort > 2013-04-02 03:37:33,095 INFO org.mortbay.log: Logging to > org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via > org.mortbay.log.Slf4jLog > 2013-04-02 03:37:33,175 INFO org.apache.hadoop.http.HttpServer: Added > global filter 'safety' > (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter) > 2013-04-02 03:37:33,178 INFO org.apache.hadoop.http.HttpServer: Added > filter static_user_filter > (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) > to context master > 2013-04-02 03:37:33,178 INFO org.apache.hadoop.http.HttpServer: Added > filter static_user_filter > (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) > to context static > 2013-04-02 03:37:33,200 INFO org.apache.hadoop.http.HttpServer: Jetty > bound to port 60010 > 2013-04-02 03:37:33,200 INFO org.mortbay.log: jetty-6.1.26.cloudera.2 > 2013-04-02 03:37:33,880 INFO org.mortbay.log: Started > [email protected]:60010 > 2013-04-02 03:37:33,881 INFO > org.apache.hadoop.hbase.master.ServerManager: Waiting for region > servers count to settle; currently checked in 0, slept for 0 ms, > expecting minimum of 1, maximum of 2147483647, timeout of 4500 ms, > interval of 1500 ms. > 2013-04-02 03:37:34,079 INFO > org.apache.hadoop.hbase.master.ServerManager: Registering > server=test3.jayeson.com.sg,60020,1364873839936 > 2013-04-02 03:37:34,084 INFO > org.apache.hadoop.hbase.master.ServerManager: Registering > server=test2.jayeson.com.sg,60020,1364873841105 > 2013-04-02 03:37:34,085 INFO > org.apache.hadoop.hbase.master.ServerManager: Registering > server=server.epicoders.com,60020,1364873849637 > 2013-04-02 03:37:34,091 INFO > org.apache.hadoop.hbase.master.ServerManager: Waiting for region > servers count to settle; currently checked in 3, slept for 210 ms, > expecting minimum of 1, maximum of 2147483647, timeout of 4500 ms, > interval of 1500 ms. > 2013-04-02 03:37:34,103 WARN org.apache.hadoop.conf.Configuration: > fs.default.name is deprecated. Instead, use fs.defaultFS > 2013-04-02 03:37:35,634 INFO > org.apache.hadoop.hbase.master.ServerManager: Finished waiting for > region servers count to settle; checked in 3, slept for 1752 ms, > expecting minimum of 1, maximum of 2147483647, master is running. > 2013-04-02 03:37:35,639 INFO > org.apache.hadoop.hbase.master.MasterFileSystem: Log folder > hdfs:// > server.epicoders.com:8020/hbase/.logs/server.epicoders.com,60020,1364873849637 > belongs to an existing region server > 2013-04-02 03:37:35,639 INFO > org.apache.hadoop.hbase.master.MasterFileSystem: Log folder > hdfs:// > server.epicoders.com:8020/hbase/.logs/test2.jayeson.com.sg,60020,1364873841105 > belongs to an existing region server > 2013-04-02 03:37:35,640 INFO > org.apache.hadoop.hbase.master.MasterFileSystem: Log folder > hdfs:// > server.epicoders.com:8020/hbase/.logs/test3.jayeson.com.sg,60020,1364873839936 > belongs to an existing region server > 2013-04-02 03:37:35,640 INFO > org.apache.hadoop.hbase.master.MasterFileSystem: No logs to split > 2013-04-02 03:37:35,669 INFO org.apache.zookeeper.ZooKeeper: > Initiating client connection, connectString=server.epicoders.com:2181 > sessionTimeout=60000 watcher=hconnection > 2013-04-02 03:37:35,671 INFO org.apache.zookeeper.ClientCnxn: Opening > socket connection to server server.epicoders.com/<ip-address>:2181. > Will not attempt to authenticate using SASL (Unable to locate a login > configuration) > 2013-04-02 03:37:35,672 INFO org.apache.zookeeper.ClientCnxn: Socket > connection established to server.epicoders.com/<ip-address>:2181, > initiating session > 2013-04-02 03:37:35,673 INFO > org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper: The identifier > of this process is [email protected] > 2013-04-02 03:37:35,676 INFO org.apache.zookeeper.ClientCnxn: Session > establishment complete on server > server.epicoders.com/<ip-address>:2181, sessionid = 0x13daf9ed2b90088, > negotiated timeout = 60000 > 2013-04-02 03:37:35,730 INFO > org.apache.hadoop.hbase.catalog.CatalogTracker: Failed verification of > -ROOT-,,0 at address=server.epicoders.com,60020,1364559783898; > org.apache.hadoop.hbase.NotServingRegionException: > org.apache.hadoop.hbase.NotServingRegionException: Region is not > online: -ROOT-,,0 > at > org.apache.hadoop.hbase.regionserver.HRegionServer.getRegion(HRegionServer.java:3211) > at > org.apache.hadoop.hbase.regionserver.HRegionServer.getRegionInfo(HRegionServer.java:1996) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > at java.lang.reflect.Method.invoke(Method.java:597) > at > org.apache.hadoop.hbase.ipc.WritableRpcEngine$Server.call(WritableRpcEngine.java:364) > at > org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1400) > > 2013-04-02 03:37:35,733 INFO > org.apache.hadoop.hbase.catalog.RootLocationEditor: Unsetting ROOT > region location in ZooKeeper > 2013-04-02 03:37:36,654 INFO > org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling > OPENED event for -ROOT-,,0.70236052 from > test3.jayeson.com.sg,60020,1364873839936; deleting unassigned node > 2013-04-02 03:37:36,663 INFO > org.apache.hadoop.hbase.master.AssignmentManager: The master has > opened the region -ROOT-,,0.70236052 that was online on > test3.jayeson.com.sg,60020,1364873839936 > 2013-04-02 03:37:36,683 INFO org.apache.hadoop.hbase.master.HMaster: > -ROOT- assigned=1, rit=false, > location=test3.jayeson.com.sg,60020,1364873839936 > 2013-04-02 03:37:36,797 INFO > org.apache.hadoop.hbase.catalog.CatalogTracker: Failed verification of > .META.,,1 at address=server.epicoders.com,60020,1364559783898; > org.apache.hadoop.hbase.NotServingRegionException: > org.apache.hadoop.hbase.NotServingRegionException: Region is not > online: .META.,,1 > at > org.apache.hadoop.hbase.regionserver.HRegionServer.getRegion(HRegionServer.java:3211) > at > org.apache.hadoop.hbase.regionserver.HRegionServer.getRegionInfo(HRegionServer.java:1996) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > at java.lang.reflect.Method.invoke(Method.java:597) > at > org.apache.hadoop.hbase.ipc.WritableRpcEngine$Server.call(WritableRpcEngine.java:364) > at > org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1400) > > > After continuing with same error for a while the log ends with, > > 2013-04-02 03:37:39,281 INFO > org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling > OPENED event for .META.,,1.1028785192 from > test2.jayeson.com.sg,60020,1364873841105; deleting unassigned node > 2013-04-02 03:37:39,328 INFO > org.apache.hadoop.hbase.master.AssignmentManager: The master has > opened the region .META.,,1.1028785192 that was online on > test2.jayeson.com.sg,60020,1364873841105 > 2013-04-02 03:37:39,335 INFO org.apache.hadoop.hbase.master.HMaster: > .META. assigned=2, rit=false, > location=test2.jayeson.com.sg,60020,1364873841105 > 2013-04-02 03:37:39,359 INFO > org.apache.hadoop.hbase.catalog.MetaMigrationRemovingHTD: Meta > version=0; migrated=true > 2013-04-02 03:37:39,359 INFO > org.apache.hadoop.hbase.catalog.MetaMigrationRemovingHTD: ROOT/Meta > already up-to date with new HRI. > 2013-04-02 03:37:39,472 INFO > org.apache.hadoop.hbase.master.AssignmentManager: Clean cluster > startup. Assigning userregions > 2013-04-02 03:37:39,535 INFO > org.apache.hadoop.hbase.master.LoadBalancer: Reassigned 2 regions. 2 > retained the pre-restart assignment. > 2013-04-02 03:37:39,535 INFO > org.apache.hadoop.hbase.master.AssignmentManager: Bulk assigning 2 > region(s) across 3 server(s), retainAssignment=true > 2013-04-02 03:37:39,541 INFO > org.apache.hadoop.hbase.master.AssignmentManager: Bulk assigning done > 2013-04-02 03:37:39,562 INFO org.apache.hadoop.hbase.master.HMaster: > Registered HMaster MXBean > 2013-04-02 03:37:39,562 INFO org.apache.hadoop.hbase.master.HMaster: > Master has completed initialization > 2013-04-02 03:37:39,577 INFO > org.apache.hadoop.hbase.master.AssignmentManager: > test2.jayeson.com.sg,60020,1364873841105 unassigned znodes=1 of > total=1 > 2013-04-02 03:37:39,578 INFO > org.apache.hadoop.hbase.master.AssignmentManager: > test3.jayeson.com.sg,60020,1364873839936 unassigned znodes=1 of > total=1 > > Finally i could see the service is running fine and can access and write > data into hbase from shell. However i want to know if these errors mean > anything or affect any behavior of hbase ? > > -- > Regards, > Praveen Bysani > http://www.praveenbysani.com >
