[
https://issues.apache.org/jira/browse/ACCUMULO-3859?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14563241#comment-14563241
]
Josh Elser commented on ACCUMULO-3859:
--------------------------------------
Ok, got to the bottom of the race condition: ClientServiceHandler.testClassLoad
(invoked via addConstraint) races against the Tablet constructor. The Tablet
can miss all observer updates via the following situation with threads t1 and
t2 and table configuration instances tc1 and tc2:
1. t1: Tablet constructor is invoked
2. t1: Tablet constructor creates new TableConfiguration (tc1)
3. t2: testClassLoad is invoked by client as part of addConstraint
implementation
4. t2: testClassLoad impl creates new TableConfiguration
5. t1: tc1 cached
6. t2: tc2 cached
7. t1: ConstraintChecker observer added to tc1
Eventually, the TableConfWatcher will try to get _the_ TableConfiguration for
the table, and get tc2, not tc1. tc2 has no observers set from the tablet, only
tc1 has these. Thus, the Tablet will never get constraint or default security
label changes until it's unassigned and reloaded elsewhere.
> TabletServer never acknowledged constraint
> ------------------------------------------
>
> Key: ACCUMULO-3859
> URL: https://issues.apache.org/jira/browse/ACCUMULO-3859
> Project: Accumulo
> Issue Type: Bug
> Components: tserver
> Affects Versions: 1.6.2, 1.7.0
> Reporter: Josh Elser
> Assignee: Josh Elser
> Priority: Blocker
> Fix For: 1.6.3, 1.8.0, 1.7.1
>
>
> Still debugging the ProxyITs, I came across a case where the test timed out
> after 4 minutes of repeatedly trying to write a mutation which should fail
> but never did.
> {noformat}
> testTableConstraints(org.apache.accumulo.proxy.TTupleProxyIT) Time elapsed:
> 240.016 sec <<< ERROR!
> java.lang.Exception: test timed out after 240000 milliseconds
> at java.lang.Thread.sleep(Native Method)
> at
> org.apache.accumulo.core.util.UtilWaitThread.sleep(UtilWaitThread.java:27)
> at
> org.apache.accumulo.proxy.SimpleProxyBase.testTableConstraints(SimpleProxyBase.java:1220)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:497)
> at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
> at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)
> at
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
> at
> org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
> at
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
> at
> org.junit.internal.runners.statements.FailOnTimeout$StatementThread.run(FailOnTimeout.java:74)
> {noformat}
> {noformat}
> $ fgrep ConstraintChecker TabletServer_*.out | fgrep 1x
> TabletServer_1376790324.out:2015-05-28 00:53:16,936
> [constraints.ConstraintChecker] DEBUG: Loaded constraint
> org.apache.accumulo.core.constraints.DefaultKeySizeConstraint for 1x
> $ fgrep testTableConstraints Master_1374754488.out
> 2015-05-28 00:53:16,184 [Audit] INFO : operation: permitted; user: root;
> client: 192.168.11.101:49900; action: createTable; targetTable:
> TTupleProxyIT_testTableConstraints0;
> 2015-05-28 00:53:16,677 [tables.TableManager] DEBUG: Creating ZooKeeper
> entries for new table TTupleProxyIT_testTableConstraints0 (ID: 1x) in
> namespace (ID: +default)
> 2015-05-28 00:53:16,772 [master.EventCoordinator] INFO : Created table
> TTupleProxyIT_testTableConstraints0
> 2015-05-28 00:53:16,772 [tableOps.FinishCreateTable] DEBUG: Created table 1x
> TTupleProxyIT_testTableConstraints0
> $ fgrep ConstraintChecker TabletServer_*.out | fgrep 1x
> TabletServer_1376790324.out:2015-05-28 00:53:16,936
> [constraints.ConstraintChecker] DEBUG: Loaded constraint
> org.apache.accumulo.core.constraints.DefaultKeySizeConstraint for 1x
> {noformat}
> {noformat}
> 2015-05-28 00:53:16,724 [server.FinalRequestProcessor] DEBUG: Processing
> request:: sessionid:0x14d9792a5db0006 type:exists cxid:0xe52a
> zxid:0xfffffffffffffffe txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.1
> 2015-05-28 00:53:16,724 [server.FinalRequestProcessor] DEBUG:
> sessionid:0x14d9792a5db0006 type:exists cxid:0xe52a zxid:0xfffffffffffffffe
> txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.1
> 2015-05-28 00:53:16,724 [server.FinalRequestProcessor] DEBUG: Processing
> request:: sessionid:0x14d9792a5db0006 type:getData cxid:0xe52b
> zxid:0xfffffffffffffffe txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.1
> 2015-05-28 00:53:16,724 [server.FinalRequestProcessor] DEBUG:
> sessionid:0x14d9792a5db0006 type:getData cxid:0xe52b zxid:0xfffffffffffffffe
> txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.1
> 2015-05-28 00:53:16,872 [server.FinalRequestProcessor] DEBUG: Processing
> request:: sessionid:0x14d9792a5db0003 type:exists cxid:0xcc4
> zxid:0xfffffffffffffffe txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.1
> 2015-05-28 00:53:16,872 [server.FinalRequestProcessor] DEBUG:
> sessionid:0x14d9792a5db0003 type:exists cxid:0xcc4 zxid:0xfffffffffffffffe
> txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.1
> 2015-05-28 00:53:16,873 [server.FinalRequestProcessor] DEBUG: Processing
> request:: sessionid:0x14d9792a5db0003 type:getData cxid:0xcc5
> zxid:0xfffffffffffffffe txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.1
> 2015-05-28 00:53:16,873 [server.FinalRequestProcessor] DEBUG:
> sessionid:0x14d9792a5db0003 type:getData cxid:0xcc5 zxid:0xfffffffffffffffe
> txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.1
> 2015-05-28 00:53:16,912 [server.FinalRequestProcessor] DEBUG: Processing
> request:: sessionid:0x14d9792a5db0002 type:exists cxid:0xdd7
> zxid:0xfffffffffffffffe txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.1
> 2015-05-28 00:53:16,912 [server.FinalRequestProcessor] DEBUG:
> sessionid:0x14d9792a5db0002 type:exists cxid:0xdd7 zxid:0xfffffffffffffffe
> txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.1
> 2015-05-28 00:53:16,913 [server.FinalRequestProcessor] DEBUG: Processing
> request:: sessionid:0x14d9792a5db0002 type:getData cxid:0xdd8
> zxid:0xfffffffffffffffe txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.1
> 2015-05-28 00:53:16,913 [server.FinalRequestProcessor] DEBUG:
> sessionid:0x14d9792a5db0002 type:getData cxid:0xdd8 zxid:0xfffffffffffffffe
> txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.1
> 2015-05-28 00:53:16,934 [server.FinalRequestProcessor] DEBUG: Processing
> request:: sessionid:0x14d9792a5db0002 type:exists cxid:0xde6
> zxid:0xfffffffffffffffe txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.1
> 2015-05-28 00:53:16,934 [server.FinalRequestProcessor] DEBUG:
> sessionid:0x14d9792a5db0002 type:exists cxid:0xde6 zxid:0xfffffffffffffffe
> txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.1
> 2015-05-28 00:53:16,934 [server.FinalRequestProcessor] DEBUG: Processing
> request:: sessionid:0x14d9792a5db0002 type:getData cxid:0xde7
> zxid:0xfffffffffffffffe txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.1
> 2015-05-28 00:53:16,934 [server.FinalRequestProcessor] DEBUG:
> sessionid:0x14d9792a5db0002 type:getData cxid:0xde7 zxid:0xfffffffffffffffe
> txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.1
> 2015-05-28 00:53:26,959 [server.FinalRequestProcessor] DEBUG: Processing
> request:: sessionid:0x14d9792a5db0002 type:exists cxid:0xe15
> zxid:0xfffffffffffffffe txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.1
> 2015-05-28 00:53:26,959 [server.FinalRequestProcessor] DEBUG:
> sessionid:0x14d9792a5db0002 type:exists cxid:0xe15 zxid:0xfffffffffffffffe
> txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.1
> 2015-05-28 00:53:26,959 [server.FinalRequestProcessor] DEBUG: Processing
> request:: sessionid:0x14d9792a5db0002 type:getData cxid:0xe16
> zxid:0xfffffffffffffffe txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.1
> 2015-05-28 00:53:26,959 [server.FinalRequestProcessor] DEBUG:
> sessionid:0x14d9792a5db0002 type:getData cxid:0xe16 zxid:0xfffffffffffffffe
> txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.1
> 2015-05-28 00:53:26,959 [server.FinalRequestProcessor] DEBUG: Processing
> request:: sessionid:0x14d9792a5db0002 type:exists cxid:0xe17
> zxid:0xfffffffffffffffe txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.2
> 2015-05-28 00:53:26,959 [server.FinalRequestProcessor] DEBUG:
> sessionid:0x14d9792a5db0002 type:exists cxid:0xe17 zxid:0xfffffffffffffffe
> txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.2
> 2015-05-28 00:53:26,959 [server.FinalRequestProcessor] DEBUG: Processing
> request:: sessionid:0x14d9792a5db0002 type:getData cxid:0xe18
> zxid:0xfffffffffffffffe txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.2
> 2015-05-28 00:53:26,959 [server.FinalRequestProcessor] DEBUG:
> sessionid:0x14d9792a5db0002 type:getData cxid:0xe18 zxid:0xfffffffffffffffe
> txntype:unknown
> reqpath:/accumulo/159cfd2e-308b-4af8-8974-1f0d44f64017/tables/1x/conf/table.constraint.2
> {noformat}
> It appears that the TabletServer just _never_ got the nodeChildrenChanged
> update (or just ignored it) and thus the test retried until it timed out.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
