accumulo-notifications mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Josh Elser (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (ACCUMULO-3859) TabletServer never acknowledged constraint
Date Thu, 28 May 2015 16:56:18 GMT

    [ 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)

Mime
View raw message