You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@hbase.apache.org by "Xiaolin Ha (JIRA)" <ji...@apache.org> on 2018/11/01 06:35:00 UTC

[jira] [Updated] (HBASE-21331) TestAccessController.testRemoteLocks is flakey

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

Xiaolin Ha updated HBASE-21331:
-------------------------------
    Description: 
TestAccessController.testRemoteLocks might return {color:#205081}java.lang.AssertionError: Expected action to pass for user 'qLTableACUser' but was denied
	at org.apache.hadoop.hbase.security.access.TestAccessController.testRemoteLocks(TestAccessController.java:3017)​{color}

Should pause a while to wait for the permission change to propagate to all watchers.
Similar to HBASE-10465。


Error logs are as follows:

{color:#205081}2018-10-15 16:35:03,292 INFO  [RS-EventLoopGroup-6-3] ipc.ServerRpcConnection(556): Connection from 172.32.9.50:34590, version=2.1.0-mdh3-SNAPSHOT, sasl=false, ugi=default (auth:SIMPLE), service=ClientService
2018-10-15 16:35:03,300 DEBUG [RpcServer.priority.FPBQ.Fifo.handler=8,queue=0,port=42095] access.AccessController(2045): Received request to grant access permission UserPermission: user=qLTableACUser, [TablePermission: table=preQueueNs:testRemoteLocks, family=null, qualifier=null, actions=ADMIN,CREATE]
2018-10-15 16:35:03,301 DEBUG [RpcServer.priority.FPBQ.Fifo.handler=8,queue=0,port=42095] access.AccessControlLists(181): Writing permission with rowKey preQueueNs:testRemoteLocks qLTableACUser: CA
2018-10-15 16:35:03,304 DEBUG [htable-pool1175-t1] access.AccessControlLists(607): Read acl: kv [qLTableACUser: CA]
2018-10-15 16:35:03,305 DEBUG [htable-pool1175-t1] access.AccessControlLists(607): Read acl: kv [qLTableRWXUser: RWX]
2018-10-15 16:35:03,310 DEBUG [Time-limited test-EventThread] zookeeper.ZKWatcher(485): regionserver:42095-0x16676dbff930001, quorum=localhost:49645, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/acl/preQueueNs:testRemoteLocks
2018-10-15 16:35:03,344 DEBUG [Time-limited test-EventThread] zookeeper.ZKWatcher(485): master:34983-0x16676dbff930000, quorum=localhost:49645, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/acl/preQueueNs:testRemoteLocks
2018-10-15 16:35:03,367 INFO  [Time-limited test] zookeeper.ReadOnlyZKClient(350): Close zookeeper connection 0x5d6295fe to localhost:49645
2018-10-15 16:35:03,368 DEBUG [Time-limited test] ipc.AbstractRpcClient(491): Stopping rpc client
2018-10-15 16:35:03,369 INFO  [Time-limited test] hbase.Waiter(189): Waiting up to [10,000] milli-secs(wait.for.ratio=[1])
2018-10-15 16:35:03,369 INFO  [Time-limited test] access.SecureTestUtil$1(356): AccessController on region hbase:acl,,1539592430177.caa9354e41bc4d1d52f493194490f66c. has not updated: mtime=219
2018-10-15 16:35:03,440 DEBUG [zk-permission-watcher2-thread-1] access.ZKPermissionWatcher(245): Updating permissions cache from preQueueNs:testRemoteLocks with data PBUF\x0A8\x0A\x0DqLTableACUser\x12'\x08\x03"#\x0A\x1D\x0A\x0ApreQueueNs\x12\x0FtestRemoteLocks \x03 \x04\x0A;\x0A\x0EqLTableRWXUser\x12)\x08\x03"%\x0A\x1D\x0A\x0ApreQueueNs\x12\x0FtestRemoteLocks \x00 \x01 \x02​{color}​

  was:
TestAccessController.testRemoteLocks might return {color:#205081}java.lang.AssertionError: Expected action to pass for user 'qLTableACUser' but was denied
	at org.apache.hadoop.hbase.security.access.TestAccessController.testRemoteLocks(TestAccessController.java:3017)​{color}
Because when checking the assertion after the test WAIT_TIME, the update of hbase:acl has not completed.

Error logs are as follows:

{color:#205081}2018-10-15 16:35:03,292 INFO  [RS-EventLoopGroup-6-3] ipc.ServerRpcConnection(556): Connection from 172.32.9.50:34590, version=2.1.0-mdh3-SNAPSHOT, sasl=false, ugi=default (auth:SIMPLE), service=ClientService
2018-10-15 16:35:03,300 DEBUG [RpcServer.priority.FPBQ.Fifo.handler=8,queue=0,port=42095] access.AccessController(2045): Received request to grant access permission UserPermission: user=qLTableACUser, [TablePermission: table=preQueueNs:testRemoteLocks, family=null, qualifier=null, actions=ADMIN,CREATE]
2018-10-15 16:35:03,301 DEBUG [RpcServer.priority.FPBQ.Fifo.handler=8,queue=0,port=42095] access.AccessControlLists(181): Writing permission with rowKey preQueueNs:testRemoteLocks qLTableACUser: CA
2018-10-15 16:35:03,304 DEBUG [htable-pool1175-t1] access.AccessControlLists(607): Read acl: kv [qLTableACUser: CA]
2018-10-15 16:35:03,305 DEBUG [htable-pool1175-t1] access.AccessControlLists(607): Read acl: kv [qLTableRWXUser: RWX]
2018-10-15 16:35:03,310 DEBUG [Time-limited test-EventThread] zookeeper.ZKWatcher(485): regionserver:42095-0x16676dbff930001, quorum=localhost:49645, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/acl/preQueueNs:testRemoteLocks
2018-10-15 16:35:03,344 DEBUG [Time-limited test-EventThread] zookeeper.ZKWatcher(485): master:34983-0x16676dbff930000, quorum=localhost:49645, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/acl/preQueueNs:testRemoteLocks
2018-10-15 16:35:03,367 INFO  [Time-limited test] zookeeper.ReadOnlyZKClient(350): Close zookeeper connection 0x5d6295fe to localhost:49645
2018-10-15 16:35:03,368 DEBUG [Time-limited test] ipc.AbstractRpcClient(491): Stopping rpc client
2018-10-15 16:35:03,369 INFO  [Time-limited test] hbase.Waiter(189): Waiting up to [10,000] milli-secs(wait.for.ratio=[1])
2018-10-15 16:35:03,369 INFO  [Time-limited test] access.SecureTestUtil$1(356): AccessController on region hbase:acl,,1539592430177.caa9354e41bc4d1d52f493194490f66c. has not updated: mtime=219
2018-10-15 16:35:03,440 DEBUG [zk-permission-watcher2-thread-1] access.ZKPermissionWatcher(245): Updating permissions cache from preQueueNs:testRemoteLocks with data PBUF\x0A8\x0A\x0DqLTableACUser\x12'\x08\x03"#\x0A\x1D\x0A\x0ApreQueueNs\x12\x0FtestRemoteLocks \x03 \x04\x0A;\x0A\x0EqLTableRWXUser\x12)\x08\x03"%\x0A\x1D\x0A\x0ApreQueueNs\x12\x0FtestRemoteLocks \x00 \x01 \x02​{color}​


> TestAccessController.testRemoteLocks is flakey
> ----------------------------------------------
>
>                 Key: HBASE-21331
>                 URL: https://issues.apache.org/jira/browse/HBASE-21331
>             Project: HBase
>          Issue Type: Bug
>          Components: flakey
>            Reporter: Xiaolin Ha
>            Assignee: Xiaolin Ha
>            Priority: Major
>             Fix For: 3.0.0, 2.2.0
>
>
> TestAccessController.testRemoteLocks might return {color:#205081}java.lang.AssertionError: Expected action to pass for user 'qLTableACUser' but was denied
> 	at org.apache.hadoop.hbase.security.access.TestAccessController.testRemoteLocks(TestAccessController.java:3017)​{color}
> Should pause a while to wait for the permission change to propagate to all watchers.
> Similar to HBASE-10465。
> Error logs are as follows:
> {color:#205081}2018-10-15 16:35:03,292 INFO  [RS-EventLoopGroup-6-3] ipc.ServerRpcConnection(556): Connection from 172.32.9.50:34590, version=2.1.0-mdh3-SNAPSHOT, sasl=false, ugi=default (auth:SIMPLE), service=ClientService
> 2018-10-15 16:35:03,300 DEBUG [RpcServer.priority.FPBQ.Fifo.handler=8,queue=0,port=42095] access.AccessController(2045): Received request to grant access permission UserPermission: user=qLTableACUser, [TablePermission: table=preQueueNs:testRemoteLocks, family=null, qualifier=null, actions=ADMIN,CREATE]
> 2018-10-15 16:35:03,301 DEBUG [RpcServer.priority.FPBQ.Fifo.handler=8,queue=0,port=42095] access.AccessControlLists(181): Writing permission with rowKey preQueueNs:testRemoteLocks qLTableACUser: CA
> 2018-10-15 16:35:03,304 DEBUG [htable-pool1175-t1] access.AccessControlLists(607): Read acl: kv [qLTableACUser: CA]
> 2018-10-15 16:35:03,305 DEBUG [htable-pool1175-t1] access.AccessControlLists(607): Read acl: kv [qLTableRWXUser: RWX]
> 2018-10-15 16:35:03,310 DEBUG [Time-limited test-EventThread] zookeeper.ZKWatcher(485): regionserver:42095-0x16676dbff930001, quorum=localhost:49645, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/acl/preQueueNs:testRemoteLocks
> 2018-10-15 16:35:03,344 DEBUG [Time-limited test-EventThread] zookeeper.ZKWatcher(485): master:34983-0x16676dbff930000, quorum=localhost:49645, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/acl/preQueueNs:testRemoteLocks
> 2018-10-15 16:35:03,367 INFO  [Time-limited test] zookeeper.ReadOnlyZKClient(350): Close zookeeper connection 0x5d6295fe to localhost:49645
> 2018-10-15 16:35:03,368 DEBUG [Time-limited test] ipc.AbstractRpcClient(491): Stopping rpc client
> 2018-10-15 16:35:03,369 INFO  [Time-limited test] hbase.Waiter(189): Waiting up to [10,000] milli-secs(wait.for.ratio=[1])
> 2018-10-15 16:35:03,369 INFO  [Time-limited test] access.SecureTestUtil$1(356): AccessController on region hbase:acl,,1539592430177.caa9354e41bc4d1d52f493194490f66c. has not updated: mtime=219
> 2018-10-15 16:35:03,440 DEBUG [zk-permission-watcher2-thread-1] access.ZKPermissionWatcher(245): Updating permissions cache from preQueueNs:testRemoteLocks with data PBUF\x0A8\x0A\x0DqLTableACUser\x12'\x08\x03"#\x0A\x1D\x0A\x0ApreQueueNs\x12\x0FtestRemoteLocks \x03 \x04\x0A;\x0A\x0EqLTableRWXUser\x12)\x08\x03"%\x0A\x1D\x0A\x0ApreQueueNs\x12\x0FtestRemoteLocks \x00 \x01 \x02​{color}​



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)