[PHOENIX-1473] Connecting with Phoenix client when Phoenix is not deployed on region server(s) takes down region server(s).

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Won't Fix
• Affects Version/s: 4.2.0
• Assignee: Unassigned
• Reporter: Serhiy Bilousov
• Created: 20/Nov/14 15:53
• Updated: 04/Dec/14 21:42
• Resolved: 04/Dec/14 21:42

Description

When attempting to connect with Phoenix client when Phoenix server not deployed will take down region servers. It looks like problem with creating SYSTEM.CATALOG table causing it. It may be argued that there some improvements can be done on HBase side in regards to not allow to create table if coprocessor jar files could not be found but from Phoenix side I would think before doing anything it should check if required jar is in place (meaning Phoenix deployed properly).

here is log from region server

2014-11-20 14:29:48,411 ERROR [RS_OPEN_REGION-dn01:60020-1] handler.OpenRegionHandler: Failed open of region=SYSTEM.CATALOG,,1416493787900.35b7b3a19f75688fce382e8f1323b4ae., starting to roll back the global memstore size.
java.io.IOException: Unable to load configured region split policy 'org.apache.phoenix.schema.MetaDataSplitPolicy' for table 'SYSTEM.CATALOG'
at org.apache.hadoop.hbase.regionserver.RegionSplitPolicy.getSplitPolicyClass(RegionSplitPolicy.java:121)
at org.apache.hadoop.hbase.regionserver.RegionSplitPolicy.create(RegionSplitPolicy.java:101)
at org.apache.hadoop.hbase.regionserver.HRegion.initializeRegionInternals(HRegion.java:727)
at org.apache.hadoop.hbase.regionserver.HRegion.initialize(HRegion.java:684)
at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:4550)
at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:4520)
at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:4492)
at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:4448)
at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:4399)
at org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.openRegion(OpenRegionHandler.java:465)
at org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.process(OpenRegionHandler.java:139)
at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:128)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
Caused by: java.lang.ClassNotFoundException: org.apache.phoenix.schema.MetaDataSplitPolicy
at java.net.URLClassLoader$1.run(Unknown Source)
at java.net.URLClassLoader$1.run(Unknown Source)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.URLClassLoader.findClass(Unknown Source)
at java.lang.ClassLoader.loadClass(Unknown Source)
at sun.misc.Launcher$AppClassLoader.loadClass(Unknown Source)
at java.lang.ClassLoader.loadClass(Unknown Source)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Unknown Source)
at org.apache.hadoop.hbase.regionserver.RegionSplitPolicy.getSplitPolicyClass(RegionSplitPolicy.java:117)
... 14 more
2014-11-20 14:29:48,411 INFO [RS_OPEN_REGION-dn01:60020-1] handler.OpenRegionHandler: Opening of region

{ENCODED => 35b7b3a19f75688fce382e8f1323b4ae, NAME => 'SYSTEM.CATALOG,,1416493787900.35b7b3a19f75688fce382e8f1323b4ae.', STARTKEY => '', ENDKEY => ''}

failed, transitioning from OPENING to FAILED_OPEN in ZK, expecting version 4
2014-11-20 14:29:48,412 DEBUG [RS_OPEN_REGION-dn01:60020-1] zookeeper.ZKAssign: regionserver:60020-0x349cd39697a00e5, quorum=nn02.abc.com:2181,nn01.abc.com:2181,jz01.abc.com:2181, baseZNode=/hbase Transitioning 35b7b3a19f75688fce382e8f1323b4ae from RS_ZK_REGION_OPENING to RS_ZK_REGION_FAILED_OPEN
2014-11-20 14:29:48,414 DEBUG [RS_OPEN_REGION-dn01:60020-1] zookeeper.ZKAssign: regionserver:60020-0x349cd39697a00e5, quorum=nn02.abc.com:2181,nn01.abc.com:2181,z01.abc.com:2181, baseZNode=/hbase Transitioned node 35b7b3a19f75688fce382e8f1323b4ae from RS_ZK_REGION_OPENING to RS_ZK_REGION_FAILED_OPEN
2014-11-20 14:29:48,528 INFO [regionserver60020] regionserver.HRegionServer: stopping server dn01.abc.com,60020,1416493546924; all regions closed.
2014-11-20 14:29:48,528 DEBUG [regionserver60020-WAL.AsyncNotifier] wal.FSHLog: regionserver60020-WAL.AsyncNotifier interrupted while waiting for notification from AsyncSyncer thread
2014-11-20 14:29:48,528 INFO [regionserver60020-WAL.AsyncNotifier] wal.FSHLog: regionserver60020-WAL.AsyncNotifier exiting
2014-11-20 14:29:48,529 DEBUG [regionserver60020-WAL.AsyncSyncer0] wal.FSHLog: regionserver60020-WAL.AsyncSyncer0 interrupted while waiting for notification from AsyncWriter thread
2014-11-20 14:29:48,529 INFO [regionserver60020-WAL.AsyncSyncer0] wal.FSHLog: regionserver60020-WAL.AsyncSyncer0 exiting
2014-11-20 14:29:48,529 DEBUG [regionserver60020-WAL.AsyncSyncer1] wal.FSHLog: regionserver60020-WAL.AsyncSyncer1 interrupted while waiting for notification from AsyncWriter thread
2014-11-20 14:29:48,529 INFO [regionserver60020-WAL.AsyncSyncer1] wal.FSHLog: regionserver60020-WAL.AsyncSyncer1 exiting
2014-11-20 14:29:48,529 DEBUG [regionserver60020-WAL.AsyncSyncer2] wal.FSHLog: regionserver60020-WAL.AsyncSyncer2 interrupted while waiting for notification from AsyncWriter thread
2014-11-20 14:29:48,529 INFO [regionserver60020-WAL.AsyncSyncer2] wal.FSHLog: regionserver60020-WAL.AsyncSyncer2 exiting
2014-11-20 14:29:48,529 DEBUG [regionserver60020-WAL.AsyncSyncer3] wal.FSHLog: regionserver60020-WAL.AsyncSyncer3 interrupted while waiting for notification from AsyncWriter thread
2014-11-20 14:29:48,529 INFO [regionserver60020-WAL.AsyncSyncer3] wal.FSHLog: regionserver60020-WAL.AsyncSyncer3 exiting
2014-11-20 14:29:48,530 DEBUG [regionserver60020-WAL.AsyncSyncer4] wal.FSHLog: regionserver60020-WAL.AsyncSyncer4 interrupted while waiting for notification from AsyncWriter thread
2014-11-20 14:29:48,530 INFO [regionserver60020-WAL.AsyncSyncer4] wal.FSHLog: regionserver60020-WAL.AsyncSyncer4 exiting
2014-11-20 14:29:48,530 DEBUG [regionserver60020-WAL.AsyncWriter] wal.FSHLog: regionserver60020-WAL.AsyncWriter interrupted while waiting for newer writes added to local buffer
2014-11-20 14:29:48,530 INFO [regionserver60020-WAL.AsyncWriter] wal.FSHLog: regionserver60020-WAL.AsyncWriter exiting
2014-11-20 14:29:48,530 DEBUG [regionserver60020] wal.FSHLog: Closing WAL writer in hdfs://mycluster/hbase/WALs/dn01.abc.com,60020,1416493546924
2014-11-20 14:29:48,547 INFO [regionserver60020] regionserver.Leases: regionserver60020 closing leases
2014-11-20 14:29:48,547 INFO [regionserver60020] regionserver.Leases: regionserver60020 closed leases
2014-11-20 14:29:48,915 INFO [regionserver60020.periodicFlusher] regionserver.HRegionServer$PeriodicMemstoreFlusher: regionserver60020.periodicFlusher exiting
2014-11-20 14:29:48,915 INFO [regionserver60020] regionserver.CompactSplitThread: Waiting for Split Thread to finish...
2014-11-20 14:29:48,915 INFO [regionserver60020] regionserver.CompactSplitThread: Waiting for Merge Thread to finish...
2014-11-20 14:29:48,915 INFO [regionserver60020] regionserver.CompactSplitThread: Waiting for Large Compaction Thread to finish...
2014-11-20 14:29:48,916 INFO [regionserver60020] regionserver.CompactSplitThread: Waiting for Small Compaction Thread to finish...
2014-11-20 14:29:48,920 INFO [regionserver60020] client.HConnectionManager$HConnectionImplementation: Closing zookeeper sessionid=0x349cd39697a00e6
2014-11-20 14:29:48,922 INFO [regionserver60020-EventThread] zookeeper.ClientCnxn: EventThread shut down
2014-11-20 14:29:48,922 INFO [regionserver60020] zookeeper.ZooKeeper: Session: 0x349cd39697a00e6 closed
2014-11-20 14:29:48,922 INFO [regionserver60020.leaseChecker] regionserver.Leases: regionserver60020.leaseChecker closing leases
2014-11-20 14:29:48,922 INFO [regionserver60020.leaseChecker] regionserver.Leases: regionserver60020.leaseChecker closed leases
2014-11-20 14:29:48,926 INFO [regionserver60020-EventThread] zookeeper.ClientCnxn: EventThread shut down
2014-11-20 14:29:48,926 INFO [regionserver60020] zookeeper.ZooKeeper: Session: 0x349cd39697a00e5 closed
2014-11-20 14:29:48,926 INFO [regionserver60020] regionserver.HRegionServer: stopping server dn01.abc.com,60020,1416493546924; zookeeper connection closed.
2014-11-20 14:29:48,926 INFO [regionserver60020] regionserver.HRegionServer: regionserver60020 exiting
2014-11-20 14:29:48,926 ERROR [main] regionserver.HRegionServerCommandLine: Region server exiting
java.lang.RuntimeException: HRegionServer Aborted
at org.apache.hadoop.hbase.regionserver.HRegionServerCommandLine.start(HRegionServerCommandLine.java:66)
at org.apache.hadoop.hbase.regionserver.HRegionServerCommandLine.run(HRegionServerCommandLine.java:85)
at org.apache.hadoop.util.ToolRunner.run(ToolRunner.java:70)
at org.apache.hadoop.hbase.util.ServerCommandLine.doMain(ServerCommandLine.java:126)
at org.apache.hadoop.hbase.regionserver.HRegionServer.main(HRegionServer.java:2422)
2014-11-20 14:29:48,928 INFO [Thread-9] regionserver.ShutdownHook: Shutdown hook starting; hbase.shutdown.hook=true; fsShutdownHook=org.apache.hadoop.fs.FileSystem$Cache$ClientFinalizer@3e44f2a5
2014-11-20 14:29:48,928 INFO [Thread-9] regionserver.ShutdownHook: Starting fs shutdown hook thread.
2014-11-20 14:29:48,930 INFO [Thread-9] regionserver.ShutdownHook: Shutdown hook finished.

Issue Links

• is related to: HBASE-12570 Improve table configuration sanity checking