[HBASE-18475] MasterProcedureScheduler incorrectly passes null Procedure to table locking

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Fix Version/s: 2.0.0-alpha-2, 2.0.0
• Component/s: proc-v2
• Assignee: Sean Busbey
• Reporter: Sean Busbey
• Created: 28/Jul/17 21:01
• Updated: 01/Aug/18 06:24
• Resolved: 31/Jul/17 16:08

Description

Occasionally I get a series of these in tests during shutdown

2017-07-27 16:24:26,774 DEBUG [RpcServer.default.FPBQ.Fifo.handler=28,queue=1,port=37201] master.MasterRpcServices(1011): Checking to see if procedure is done procId=506
2017-07-27 16:24:26,777 INFO  [main] client.HBaseAdmin$TableFuture(3591): Operation: CREATE, Table Name: default:foo failed with foo
2017-07-27 16:24:26,782 INFO  [RpcServer.default.FPBQ.Fifo.handler=28,queue=1,port=37201] master.HMaster$4(1755): Client=jenkins//172.26.21.67 create 'foo', {NAME => 'family_1', VERSIONS => '1', EVICT_BLOCKS_ON_CLOSE => 'false', KEEP_DELETED_CELLS => 'FALSE', CACHE_DATA_ON_WRITE => 'false', DATA_BLOCK_ENCODING => 'NONE', TTL => 'FOREVER', MIN_VERSIONS => '0', REPLICATION_SCOPE => '0', BLOOMFILTER => 'ROW', CACHE_INDEX_ON_WRITE => 'false', IN_MEMORY => 'false', CACHE_BLOOMS_ON_WRITE => 'false', PREFETCH_BLOCKS_ON_OPEN => 'false', COMPRESSION => 'NONE', CACHE_DATA_IN_L1 => 'false', BLOCKCACHE => 'true', BLOCKSIZE => '65536'}
2017-07-27 16:24:26,884 DEBUG [RpcServer.default.FPBQ.Fifo.handler=28,queue=1,port=37201] procedure2.ProcedureExecutor(792): Stored pid=507, state=RUNNABLE:CREATE_TABLE_PRE_OPERATION; CreateTableProcedure table=foo
2017-07-27 16:24:26,887 DEBUG [RpcServer.default.FPBQ.Fifo.handler=28,queue=1,port=37201] master.MasterRpcServices(1011): Checking to see if procedure is done procId=507
2017-07-27 16:24:26,890 INFO  [ProcExecWrkr-5] procedure2.ProcedureExecutor(1261): Rolled back pid=507, state=ROLLEDBACK, exception=org.apache.hadoop.hbase.TableExistsException via master-create-table:org.apache.hadoop.hbase.TableExistsException: foo; CreateTableProcedure table=foo exec-time=106msec
2017-07-27 16:24:26,890 WARN  [ProcExecWrkr-5] procedure2.ProcedureExecutor$WorkerThread(1668): Worker terminating UNNATURALLY null
java.lang.NullPointerException
	at org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler.requireTableExclusiveLock(MasterProcedureScheduler.java:590)
	at org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler.access$300(MasterProcedureScheduler.java:106)
	at org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler$TableQueue.requireExclusiveLock(MasterProcedureScheduler.java:582)
	at org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler.doPoll(MasterProcedureScheduler.java:215)
	at org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler.dequeue(MasterProcedureScheduler.java:203)
	at org.apache.hadoop.hbase.procedure2.AbstractProcedureScheduler.poll(AbstractProcedureScheduler.java:145)
	at org.apache.hadoop.hbase.procedure2.AbstractProcedureScheduler.poll(AbstractProcedureScheduler.java:119)
	at org.apache.hadoop.hbase.procedure2.ProcedureExecutor$WorkerThread.run(ProcedureExecutor.java:1641)
2017-07-27 16:24:26,890 DEBUG [ProcExecWrkr-5] procedure2.ProcedureExecutor$WorkerThread(1670): Worker terminated.

Eventually all the workers are done.