[jira] [Updated] (HBASE-20038) TestLockProcedure.testTimeout is flakey

2018-02-22 Thread stack (JIRA) 

 [ 
https://issues.apache.org/jira/browse/HBASE-20038?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

stack updated HBASE-20038:
--
Resolution: Fixed
Status: Resolved  (was: Patch Available)

Resolving. This no longer shows in flakies list. Thanks [~Apache9]

> TestLockProcedure.testTimeout is flakey
> ---
>
> Key: HBASE-20038
> URL: https://issues.apache.org/jira/browse/HBASE-20038
> Project: HBase
>  Issue Type: Sub-task
>  Components: proc-v2, test
>Reporter: Duo Zhang
>Assignee: Duo Zhang
>Priority: Major
> Fix For: 2.0.0-beta-2
>
> Attachments: HBASE-20038.patch, HBASE-20038.patch, HBASE-20038.patch
>
>
> The test is simple so it is easy to find out the problem.
> {noformat}
> 2018-02-21 04:53:32,230 INFO  [Time-limited test] hbase.ResourceChecker(148): 
> before: master.locking.TestLockProcedure#testTimeout Thread=218, 
> OpenFileDescriptor=853, MaxFileDescriptor=6, SystemLoadAverage=5075, 
> ProcessCount=312, AvailableMemoryMB=5373
> 2018-02-21 04:53:32,234 WARN  [Time-limited test] 
> procedure2.ProcedureTestingUtility(146): Set Kill before store update to: 
> false
> 2018-02-21 04:53:32,278 DEBUG [Time-limited test] 
> procedure2.ProcedureExecutor(866): Stored pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:32,285 DEBUG [Time-limited test] locking.LockProcedure(195): 
> Heartbeat pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:32,286 DEBUG [PEWorker-1] locking.LockProcedure(312): LOCKED 
> pid=14, state=RUNNABLE; org.apache.hadoop.hbase.master.locking.LockProcedure, 
> namespace=namespace, type=EXCLUSIVE
> 2018-02-21 04:53:32,303 DEBUG [Time-limited test] 
> locking.TestLockProcedure(204): Proc id 14 acquired lock.
> 2018-02-21 04:53:32,298 INFO  [PEWorker-1] 
> procedure2.TimeoutExecutorThread(82): ADDED pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE; timeout=2000, timestamp=1519188814298
> 2018-02-21 04:53:33,303 DEBUG [Time-limited test] locking.LockProcedure(195): 
> Heartbeat pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:33,304 DEBUG [Time-limited test] 
> locking.TestLockProcedure(225): Proc id 14 : LOCKED.
> 2018-02-21 04:53:34,299 DEBUG [ProcExecTimeout] locking.LockProcedure(207): 
> Timeout failure ProcedureEvent for pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:34,299 DEBUG [ProcExecTimeout] locking.LockProcedure(210): 
> Calling wake on ProcedureEvent for pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:34,299 INFO  [PEWorker-1] 
> procedure2.TimeoutExecutorThread(82): ADDED pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE; timeout=2000, timestamp=1519188816299
> 2018-02-21 04:53:34,306 DEBUG [Time-limited test] locking.LockProcedure(195): 
> Heartbeat pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:34,306 DEBUG [Time-limited test] 
> locking.TestLockProcedure(225): Proc id 14 : LOCKED.
> 2018-02-21 04:53:34,766 WARN  [HBase-Metrics2-1] impl.MetricsConfig(125): 
> Cannot locate configuration: tried 
> hadoop-metrics2-hbase.properties,hadoop-metrics2.properties
> 2018-02-21 04:53:36,299 DEBUG [ProcExecTimeout] locking.LockProcedure(207): 
> Timeout failure ProcedureEvent for pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:36,299 DEBUG [ProcExecTimeout] locking.LockProcedure(210): 
> Calling wake on ProcedureEvent for pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:36,299 INFO  [PEWorker-1] 
> procedure2.TimeoutExecutorThread(

[jira] [Updated] (HBASE-20038) TestLockProcedure.testTimeout is flakey

2018-02-21 Thread stack (JIRA) 

 [ 
https://issues.apache.org/jira/browse/HBASE-20038?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

stack updated HBASE-20038:
--
Attachment: HBASE-20038.patch

> TestLockProcedure.testTimeout is flakey
> ---
>
> Key: HBASE-20038
> URL: https://issues.apache.org/jira/browse/HBASE-20038
> Project: HBase
>  Issue Type: Sub-task
>  Components: proc-v2, test
>Reporter: Duo Zhang
>Assignee: Duo Zhang
>Priority: Major
> Fix For: 2.0.0-beta-2
>
> Attachments: HBASE-20038.patch, HBASE-20038.patch, HBASE-20038.patch
>
>
> The test is simple so it is easy to find out the problem.
> {noformat}
> 2018-02-21 04:53:32,230 INFO  [Time-limited test] hbase.ResourceChecker(148): 
> before: master.locking.TestLockProcedure#testTimeout Thread=218, 
> OpenFileDescriptor=853, MaxFileDescriptor=6, SystemLoadAverage=5075, 
> ProcessCount=312, AvailableMemoryMB=5373
> 2018-02-21 04:53:32,234 WARN  [Time-limited test] 
> procedure2.ProcedureTestingUtility(146): Set Kill before store update to: 
> false
> 2018-02-21 04:53:32,278 DEBUG [Time-limited test] 
> procedure2.ProcedureExecutor(866): Stored pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:32,285 DEBUG [Time-limited test] locking.LockProcedure(195): 
> Heartbeat pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:32,286 DEBUG [PEWorker-1] locking.LockProcedure(312): LOCKED 
> pid=14, state=RUNNABLE; org.apache.hadoop.hbase.master.locking.LockProcedure, 
> namespace=namespace, type=EXCLUSIVE
> 2018-02-21 04:53:32,303 DEBUG [Time-limited test] 
> locking.TestLockProcedure(204): Proc id 14 acquired lock.
> 2018-02-21 04:53:32,298 INFO  [PEWorker-1] 
> procedure2.TimeoutExecutorThread(82): ADDED pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE; timeout=2000, timestamp=1519188814298
> 2018-02-21 04:53:33,303 DEBUG [Time-limited test] locking.LockProcedure(195): 
> Heartbeat pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:33,304 DEBUG [Time-limited test] 
> locking.TestLockProcedure(225): Proc id 14 : LOCKED.
> 2018-02-21 04:53:34,299 DEBUG [ProcExecTimeout] locking.LockProcedure(207): 
> Timeout failure ProcedureEvent for pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:34,299 DEBUG [ProcExecTimeout] locking.LockProcedure(210): 
> Calling wake on ProcedureEvent for pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:34,299 INFO  [PEWorker-1] 
> procedure2.TimeoutExecutorThread(82): ADDED pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE; timeout=2000, timestamp=1519188816299
> 2018-02-21 04:53:34,306 DEBUG [Time-limited test] locking.LockProcedure(195): 
> Heartbeat pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:34,306 DEBUG [Time-limited test] 
> locking.TestLockProcedure(225): Proc id 14 : LOCKED.
> 2018-02-21 04:53:34,766 WARN  [HBase-Metrics2-1] impl.MetricsConfig(125): 
> Cannot locate configuration: tried 
> hadoop-metrics2-hbase.properties,hadoop-metrics2.properties
> 2018-02-21 04:53:36,299 DEBUG [ProcExecTimeout] locking.LockProcedure(207): 
> Timeout failure ProcedureEvent for pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:36,299 DEBUG [ProcExecTimeout] locking.LockProcedure(210): 
> Calling wake on ProcedureEvent for pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:36,299 INFO  [PEWorker-1] 
> procedure2.TimeoutExecutorThread(82): ADDED pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namesp

[jira] [Updated] (HBASE-20038) TestLockProcedure.testTimeout is flakey

2018-02-21 Thread stack (JIRA) 

 [ 
https://issues.apache.org/jira/browse/HBASE-20038?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

stack updated HBASE-20038:
--
Attachment: HBASE-20038.patch

> TestLockProcedure.testTimeout is flakey
> ---
>
> Key: HBASE-20038
> URL: https://issues.apache.org/jira/browse/HBASE-20038
> Project: HBase
>  Issue Type: Sub-task
>  Components: proc-v2, test
>Reporter: Duo Zhang
>Assignee: Duo Zhang
>Priority: Major
> Fix For: 2.0.0-beta-2
>
> Attachments: HBASE-20038.patch, HBASE-20038.patch
>
>
> The test is simple so it is easy to find out the problem.
> {noformat}
> 2018-02-21 04:53:32,230 INFO  [Time-limited test] hbase.ResourceChecker(148): 
> before: master.locking.TestLockProcedure#testTimeout Thread=218, 
> OpenFileDescriptor=853, MaxFileDescriptor=6, SystemLoadAverage=5075, 
> ProcessCount=312, AvailableMemoryMB=5373
> 2018-02-21 04:53:32,234 WARN  [Time-limited test] 
> procedure2.ProcedureTestingUtility(146): Set Kill before store update to: 
> false
> 2018-02-21 04:53:32,278 DEBUG [Time-limited test] 
> procedure2.ProcedureExecutor(866): Stored pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:32,285 DEBUG [Time-limited test] locking.LockProcedure(195): 
> Heartbeat pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:32,286 DEBUG [PEWorker-1] locking.LockProcedure(312): LOCKED 
> pid=14, state=RUNNABLE; org.apache.hadoop.hbase.master.locking.LockProcedure, 
> namespace=namespace, type=EXCLUSIVE
> 2018-02-21 04:53:32,303 DEBUG [Time-limited test] 
> locking.TestLockProcedure(204): Proc id 14 acquired lock.
> 2018-02-21 04:53:32,298 INFO  [PEWorker-1] 
> procedure2.TimeoutExecutorThread(82): ADDED pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE; timeout=2000, timestamp=1519188814298
> 2018-02-21 04:53:33,303 DEBUG [Time-limited test] locking.LockProcedure(195): 
> Heartbeat pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:33,304 DEBUG [Time-limited test] 
> locking.TestLockProcedure(225): Proc id 14 : LOCKED.
> 2018-02-21 04:53:34,299 DEBUG [ProcExecTimeout] locking.LockProcedure(207): 
> Timeout failure ProcedureEvent for pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:34,299 DEBUG [ProcExecTimeout] locking.LockProcedure(210): 
> Calling wake on ProcedureEvent for pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:34,299 INFO  [PEWorker-1] 
> procedure2.TimeoutExecutorThread(82): ADDED pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE; timeout=2000, timestamp=1519188816299
> 2018-02-21 04:53:34,306 DEBUG [Time-limited test] locking.LockProcedure(195): 
> Heartbeat pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:34,306 DEBUG [Time-limited test] 
> locking.TestLockProcedure(225): Proc id 14 : LOCKED.
> 2018-02-21 04:53:34,766 WARN  [HBase-Metrics2-1] impl.MetricsConfig(125): 
> Cannot locate configuration: tried 
> hadoop-metrics2-hbase.properties,hadoop-metrics2.properties
> 2018-02-21 04:53:36,299 DEBUG [ProcExecTimeout] locking.LockProcedure(207): 
> Timeout failure ProcedureEvent for pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:36,299 DEBUG [ProcExecTimeout] locking.LockProcedure(210): 
> Calling wake on ProcedureEvent for pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:36,299 INFO  [PEWorker-1] 
> procedure2.TimeoutExecutorThread(82): ADDED pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> t

[jira] [Updated] (HBASE-20038) TestLockProcedure.testTimeout is flakey

2018-02-21 Thread Duo Zhang (JIRA) 

 [ 
https://issues.apache.org/jira/browse/HBASE-20038?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Duo Zhang updated HBASE-20038:
--
 Assignee: Duo Zhang
Fix Version/s: 2.0.0-beta-2
   Status: Patch Available  (was: Open)

Simple one line change. Increase to 4 * TIMEOUT.

> TestLockProcedure.testTimeout is flakey
> ---
>
> Key: HBASE-20038
> URL: https://issues.apache.org/jira/browse/HBASE-20038
> Project: HBase
>  Issue Type: Sub-task
>  Components: proc-v2, test
>Reporter: Duo Zhang
>Assignee: Duo Zhang
>Priority: Major
> Fix For: 2.0.0-beta-2
>
> Attachments: HBASE-20038.patch
>
>
> The test is simple so it is easy to find out the problem.
> {noformat}
> 2018-02-21 04:53:32,230 INFO  [Time-limited test] hbase.ResourceChecker(148): 
> before: master.locking.TestLockProcedure#testTimeout Thread=218, 
> OpenFileDescriptor=853, MaxFileDescriptor=6, SystemLoadAverage=5075, 
> ProcessCount=312, AvailableMemoryMB=5373
> 2018-02-21 04:53:32,234 WARN  [Time-limited test] 
> procedure2.ProcedureTestingUtility(146): Set Kill before store update to: 
> false
> 2018-02-21 04:53:32,278 DEBUG [Time-limited test] 
> procedure2.ProcedureExecutor(866): Stored pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:32,285 DEBUG [Time-limited test] locking.LockProcedure(195): 
> Heartbeat pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:32,286 DEBUG [PEWorker-1] locking.LockProcedure(312): LOCKED 
> pid=14, state=RUNNABLE; org.apache.hadoop.hbase.master.locking.LockProcedure, 
> namespace=namespace, type=EXCLUSIVE
> 2018-02-21 04:53:32,303 DEBUG [Time-limited test] 
> locking.TestLockProcedure(204): Proc id 14 acquired lock.
> 2018-02-21 04:53:32,298 INFO  [PEWorker-1] 
> procedure2.TimeoutExecutorThread(82): ADDED pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE; timeout=2000, timestamp=1519188814298
> 2018-02-21 04:53:33,303 DEBUG [Time-limited test] locking.LockProcedure(195): 
> Heartbeat pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:33,304 DEBUG [Time-limited test] 
> locking.TestLockProcedure(225): Proc id 14 : LOCKED.
> 2018-02-21 04:53:34,299 DEBUG [ProcExecTimeout] locking.LockProcedure(207): 
> Timeout failure ProcedureEvent for pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:34,299 DEBUG [ProcExecTimeout] locking.LockProcedure(210): 
> Calling wake on ProcedureEvent for pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:34,299 INFO  [PEWorker-1] 
> procedure2.TimeoutExecutorThread(82): ADDED pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE; timeout=2000, timestamp=1519188816299
> 2018-02-21 04:53:34,306 DEBUG [Time-limited test] locking.LockProcedure(195): 
> Heartbeat pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:34,306 DEBUG [Time-limited test] 
> locking.TestLockProcedure(225): Proc id 14 : LOCKED.
> 2018-02-21 04:53:34,766 WARN  [HBase-Metrics2-1] impl.MetricsConfig(125): 
> Cannot locate configuration: tried 
> hadoop-metrics2-hbase.properties,hadoop-metrics2.properties
> 2018-02-21 04:53:36,299 DEBUG [ProcExecTimeout] locking.LockProcedure(207): 
> Timeout failure ProcedureEvent for pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:36,299 DEBUG [ProcExecTimeout] locking.LockProcedure(210): 
> Calling wake on ProcedureEvent for pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:36,299 INFO  [PEWorker-1] 
> procedure2.TimeoutExecutorThread(82): ADDED

[jira] [Updated] (HBASE-20038) TestLockProcedure.testTimeout is flakey

2018-02-21 Thread Duo Zhang (JIRA) 

 [ 
https://issues.apache.org/jira/browse/HBASE-20038?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Duo Zhang updated HBASE-20038:
--
Component/s: test
 proc-v2

> TestLockProcedure.testTimeout is flakey
> ---
>
> Key: HBASE-20038
> URL: https://issues.apache.org/jira/browse/HBASE-20038
> Project: HBase
>  Issue Type: Sub-task
>  Components: proc-v2, test
>Reporter: Duo Zhang
>Assignee: Duo Zhang
>Priority: Major
> Fix For: 2.0.0-beta-2
>
> Attachments: HBASE-20038.patch
>
>
> The test is simple so it is easy to find out the problem.
> {noformat}
> 2018-02-21 04:53:32,230 INFO  [Time-limited test] hbase.ResourceChecker(148): 
> before: master.locking.TestLockProcedure#testTimeout Thread=218, 
> OpenFileDescriptor=853, MaxFileDescriptor=6, SystemLoadAverage=5075, 
> ProcessCount=312, AvailableMemoryMB=5373
> 2018-02-21 04:53:32,234 WARN  [Time-limited test] 
> procedure2.ProcedureTestingUtility(146): Set Kill before store update to: 
> false
> 2018-02-21 04:53:32,278 DEBUG [Time-limited test] 
> procedure2.ProcedureExecutor(866): Stored pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:32,285 DEBUG [Time-limited test] locking.LockProcedure(195): 
> Heartbeat pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:32,286 DEBUG [PEWorker-1] locking.LockProcedure(312): LOCKED 
> pid=14, state=RUNNABLE; org.apache.hadoop.hbase.master.locking.LockProcedure, 
> namespace=namespace, type=EXCLUSIVE
> 2018-02-21 04:53:32,303 DEBUG [Time-limited test] 
> locking.TestLockProcedure(204): Proc id 14 acquired lock.
> 2018-02-21 04:53:32,298 INFO  [PEWorker-1] 
> procedure2.TimeoutExecutorThread(82): ADDED pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE; timeout=2000, timestamp=1519188814298
> 2018-02-21 04:53:33,303 DEBUG [Time-limited test] locking.LockProcedure(195): 
> Heartbeat pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:33,304 DEBUG [Time-limited test] 
> locking.TestLockProcedure(225): Proc id 14 : LOCKED.
> 2018-02-21 04:53:34,299 DEBUG [ProcExecTimeout] locking.LockProcedure(207): 
> Timeout failure ProcedureEvent for pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:34,299 DEBUG [ProcExecTimeout] locking.LockProcedure(210): 
> Calling wake on ProcedureEvent for pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:34,299 INFO  [PEWorker-1] 
> procedure2.TimeoutExecutorThread(82): ADDED pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE; timeout=2000, timestamp=1519188816299
> 2018-02-21 04:53:34,306 DEBUG [Time-limited test] locking.LockProcedure(195): 
> Heartbeat pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:34,306 DEBUG [Time-limited test] 
> locking.TestLockProcedure(225): Proc id 14 : LOCKED.
> 2018-02-21 04:53:34,766 WARN  [HBase-Metrics2-1] impl.MetricsConfig(125): 
> Cannot locate configuration: tried 
> hadoop-metrics2-hbase.properties,hadoop-metrics2.properties
> 2018-02-21 04:53:36,299 DEBUG [ProcExecTimeout] locking.LockProcedure(207): 
> Timeout failure ProcedureEvent for pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:36,299 DEBUG [ProcExecTimeout] locking.LockProcedure(210): 
> Calling wake on ProcedureEvent for pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:36,299 INFO  [PEWorker-1] 
> procedure2.TimeoutExecutorThread(82): ADDED pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
>

[jira] [Updated] (HBASE-20038) TestLockProcedure.testTimeout is flakey

2018-02-21 Thread Duo Zhang (JIRA) 

 [ 
https://issues.apache.org/jira/browse/HBASE-20038?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Duo Zhang updated HBASE-20038:
--
Attachment: HBASE-20038.patch

> TestLockProcedure.testTimeout is flakey
> ---
>
> Key: HBASE-20038
> URL: https://issues.apache.org/jira/browse/HBASE-20038
> Project: HBase
>  Issue Type: Sub-task
>Reporter: Duo Zhang
>Priority: Major
> Attachments: HBASE-20038.patch
>
>
> The test is simple so it is easy to find out the problem.
> {noformat}
> 2018-02-21 04:53:32,230 INFO  [Time-limited test] hbase.ResourceChecker(148): 
> before: master.locking.TestLockProcedure#testTimeout Thread=218, 
> OpenFileDescriptor=853, MaxFileDescriptor=6, SystemLoadAverage=5075, 
> ProcessCount=312, AvailableMemoryMB=5373
> 2018-02-21 04:53:32,234 WARN  [Time-limited test] 
> procedure2.ProcedureTestingUtility(146): Set Kill before store update to: 
> false
> 2018-02-21 04:53:32,278 DEBUG [Time-limited test] 
> procedure2.ProcedureExecutor(866): Stored pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:32,285 DEBUG [Time-limited test] locking.LockProcedure(195): 
> Heartbeat pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:32,286 DEBUG [PEWorker-1] locking.LockProcedure(312): LOCKED 
> pid=14, state=RUNNABLE; org.apache.hadoop.hbase.master.locking.LockProcedure, 
> namespace=namespace, type=EXCLUSIVE
> 2018-02-21 04:53:32,303 DEBUG [Time-limited test] 
> locking.TestLockProcedure(204): Proc id 14 acquired lock.
> 2018-02-21 04:53:32,298 INFO  [PEWorker-1] 
> procedure2.TimeoutExecutorThread(82): ADDED pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE; timeout=2000, timestamp=1519188814298
> 2018-02-21 04:53:33,303 DEBUG [Time-limited test] locking.LockProcedure(195): 
> Heartbeat pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:33,304 DEBUG [Time-limited test] 
> locking.TestLockProcedure(225): Proc id 14 : LOCKED.
> 2018-02-21 04:53:34,299 DEBUG [ProcExecTimeout] locking.LockProcedure(207): 
> Timeout failure ProcedureEvent for pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:34,299 DEBUG [ProcExecTimeout] locking.LockProcedure(210): 
> Calling wake on ProcedureEvent for pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:34,299 INFO  [PEWorker-1] 
> procedure2.TimeoutExecutorThread(82): ADDED pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE; timeout=2000, timestamp=1519188816299
> 2018-02-21 04:53:34,306 DEBUG [Time-limited test] locking.LockProcedure(195): 
> Heartbeat pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE
> 2018-02-21 04:53:34,306 DEBUG [Time-limited test] 
> locking.TestLockProcedure(225): Proc id 14 : LOCKED.
> 2018-02-21 04:53:34,766 WARN  [HBase-Metrics2-1] impl.MetricsConfig(125): 
> Cannot locate configuration: tried 
> hadoop-metrics2-hbase.properties,hadoop-metrics2.properties
> 2018-02-21 04:53:36,299 DEBUG [ProcExecTimeout] locking.LockProcedure(207): 
> Timeout failure ProcedureEvent for pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:36,299 DEBUG [ProcExecTimeout] locking.LockProcedure(210): 
> Calling wake on ProcedureEvent for pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE, ready=false, [pid=14, state=RUNNABLE; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE]
> 2018-02-21 04:53:36,299 INFO  [PEWorker-1] 
> procedure2.TimeoutExecutorThread(82): ADDED pid=14, state=WAITING_TIMEOUT; 
> org.apache.hadoop.hbase.master.locking.LockProcedure, namespace=namespace, 
> type=EXCLUSIVE; timeout=2000, timestamp=1519188818299
> 2018-02-21 04:53:38,299 DEBUG [ProcExecTimeout] locking.LockProc