hbase-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Praveen Bysani <praveen.ii...@gmail.com>
Subject Re: Errors when starting Hbase service
Date Tue, 02 Apr 2013 05:33:08 GMT
Hi,

I have setup hbase using cloudera, the version it shows 'HBase
0.94.2-cdh4.2.0'. In this case both server and regionserver are the same
machine. But during other instances logs show the hostname of another
regionserver with similar errors. Just a note that the master has different
system time from the regionservers, is it an issue ?

I didn't find any errors while starting the service but there is an error
while shutting down the service. Following is the log from the region
server on the same machine during shutdown,

2013-04-02 03:36:54,390 INFO
org.apache.hadoop.hbase.regionserver.snapshot.RegionServerSnapshotManager:
Stopping RegionServerSnapshotManager gracefully.
2013-04-02 03:36:54,396 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: Waiting on 2
regions to close
2013-04-02 03:36:54,397 INFO
org.apache.hadoop.hbase.regionserver.Store: Closed info
2013-04-02 03:36:54,398 INFO
org.apache.hadoop.hbase.regionserver.HRegion: Closed
-ROOT-,,0.70236052
2013-04-02 03:36:54,426 INFO
org.apache.hadoop.hbase.regionserver.StoreFile: Delete Family Bloom
filter type for
hdfs://server.epicoders.com:8020/hbase/.META./1028785192/.tmp/1104b09fbaeb41829c2493875d7475c1:
CompoundBloomFilterWriter
2013-04-02 03:36:54,558 INFO
org.apache.hadoop.hbase.regionserver.StoreFile: NO General Bloom and
NO DeleteFamily was added to HFile
(hdfs://server.epicoders.com:8020/hbase/.META./1028785192/.tmp/1104b09fbaeb41829c2493875d7475c1)
2013-04-02 03:36:54,558 INFO
org.apache.hadoop.hbase.regionserver.Store: Flushed ,
sequenceid=90407, memsize=2.3k, into tmp file
hdfs://server.epicoders.com:8020/hbase/.META./1028785192/.tmp/1104b09fbaeb41829c2493875d7475c1
2013-04-02 03:36:54,612 INFO
org.apache.hadoop.hbase.regionserver.Store: Added
hdfs://server.epicoders.com:8020/hbase/.META./1028785192/info/1104b09fbaeb41829c2493875d7475c1,
entries=8, sequenceid=90407, filesize=1.6k
2013-04-02 03:36:54,669 INFO
org.apache.hadoop.hbase.regionserver.HRegion: Finished memstore flush
of ~2.3k/2320, currentsize=0/0 for region .META.,,1.1028785192 in
273ms, sequenceid=90407, compaction requested=false
2013-04-02 03:36:54,676 INFO
org.apache.hadoop.hbase.regionserver.Store: Closed info
2013-04-02 03:36:54,676 INFO
org.apache.hadoop.hbase.regionserver.HRegion: Closed
.META.,,1.1028785192
2013-04-02 03:36:54,799 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: stopping server
server.epicoders.com,60020,1364559783898; all regions closed.
2013-04-02 03:36:54,800 INFO
org.apache.hadoop.hbase.regionserver.wal.HLog:
regionserver60020.logSyncer exiting
2013-04-02 03:36:54,861 INFO
org.apache.hadoop.hbase.regionserver.Leases: regionserver60020 closing
leases
2013-04-02 03:36:54,862 INFO
org.apache.hadoop.hbase.regionserver.Leases: regionserver60020 closed
leases
2013-04-02 03:36:54,864 WARN
org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper: Possibly
transient ZooKeeper exception:
org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for
/hbase/rs/server.epicoders.com,60020,1364559783898
2013-04-02 03:36:54,864 INFO
org.apache.hadoop.hbase.util.RetryCounter: Sleeping 2000ms before
retry #1...
2013-04-02 03:36:56,868 WARN
org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper: Possibly
transient ZooKeeper exception:
org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for
/hbase/rs/server.epicoders.com,60020,1364559783898
2013-04-02 03:36:56,871 INFO
org.apache.hadoop.hbase.util.RetryCounter: Sleeping 4000ms before
retry #2...
2013-04-02 03:36:59,051 INFO
org.apache.hadoop.hbase.regionserver.Leases:
regionserver60020.leaseChecker closing leases
2013-04-02 03:36:59,054 INFO
org.apache.hadoop.hbase.regionserver.Leases:
regionserver60020.leaseChecker closed leases
2013-04-02 03:37:00,872 WARN
org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper: Possibly
transient ZooKeeper exception:
org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for
/hbase/rs/server.epicoders.com,60020,1364559783898
2013-04-02 03:37:00,873 INFO
org.apache.hadoop.hbase.util.RetryCounter: Sleeping 8000ms before
retry #3...
2013-04-02 03:37:08,875 WARN
org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper: Possibly
transient ZooKeeper exception:
org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for
/hbase/rs/server.epicoders.com,60020,1364559783898
2013-04-02 03:37:08,876 ERROR
org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper: ZooKeeper
delete failed after 3 retries
2013-04-02 03:37:08,876 WARN
org.apache.hadoop.hbase.regionserver.HRegionServer: Failed deleting my
ephemeral node
org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for
/hbase/rs/server.epicoders.com,60020,1364559783898
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
	at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
	at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.delete(RecoverableZooKeeper.java:137)
	at org.apache.hadoop.hbase.zookeeper.ZKUtil.deleteNode(ZKUtil.java:1215)
	at org.apache.hadoop.hbase.zookeeper.ZKUtil.deleteNode(ZKUtil.java:1204)
	at org.apache.hadoop.hbase.regionserver.HRegionServer.deleteMyEphemeralNode(HRegionServer.java:1068)
	at org.apache.hadoop.hbase.regionserver.HRegionServer.run(HRegionServer.java:846)
	at java.lang.Thread.run(Thread.java:662)
2013-04-02 03:37:08,876 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: stopping server
server.epicoders.com,60020,1364559783898; zookeeper connection closed.
2013-04-02 03:37:08,877 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: regionserver60020
exiting
2013-04-02 03:37:08,879 INFO
org.apache.hadoop.hbase.regionserver.ShutdownHook: Shutdown hook
starting; hbase.shutdown.hook=true;
fsShutdownHook=org.apache.hadoop.fs.FileSystem$Cache$ClientFinalizer@7a2431b9
2013-04-02 03:37:08,879 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: STOPPED: Shutdown
hook
2013-04-02 03:37:08,879 INFO
org.apache.hadoop.hbase.regionserver.ShutdownHook: Starting fs
shutdown hook thread.
2013-04-02 03:37:08,879 INFO
org.apache.hadoop.hbase.regionserver.ShutdownHook: Shutdown hook
finished.




On 2 April 2013 12:31, Ted Yu <yuzhihong@gmail.com> wrote:

> 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 <praveen.iiith@gmail.com
> >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
> > SelectChannelConnector@0.0.0.0: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 1043@server.epicoders.com
> > 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
> >
>



-- 
Regards,
Praveen Bysani
http://www.praveenbysani.com

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message