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 01:39:17 GMT

    [ https://issues.apache.org/jira/browse/ACCUMULO-3859?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14562157#comment-14562157
] 

Josh Elser commented on ACCUMULO-3859:
--------------------------------------

Just saw this again in SimpleProxyBase.testBatchWriter

{noformat}
2015-05-28 02:36:45,668 [Audit] INFO : operation: permitted; user: root; client: 192.168.11.101:33454;
action: createTable; targetTable: TJsonProtocolProxyIT_testBatchWriter0;
2015-05-28 02:36:45,753 [tables.TableManager] DEBUG: Creating ZooKeeper entries for new table
TJsonProtocolProxyIT_testBatchWriter0 (ID: y) in namespace (ID: +default)
2015-05-28 02:36:45,864 [master.EventCoordinator] INFO : Created table TJsonProtocolProxyIT_testBatchWriter0
2015-05-28 02:36:45,864 [tableOps.FinishCreateTable] DEBUG: Created table y TJsonProtocolProxyIT_testBatchWriter0
2015-05-28 02:38:21,498 [Audit] INFO : operation: permitted; user: root; client: 192.168.11.101:34391;
action: deleteTable; targetTable: TJsonProtocolProxyIT_testBatchWriter0;

2015-05-28 02:36:45,920 [tserver.TabletServer] INFO : Loading tablet y<<
2015-05-28 02:36:45,920 [tserver.TabletServer] INFO : hostname:33602: got assignment from
master: y<<
2015-05-28 02:36:45,920 [tserver.TabletServer] DEBUG: Loading extent: y<<
2015-05-28 02:36:45,920 [tserver.TabletServer] DEBUG: verifying extent y<<
2015-05-28 02:36:45,927 [tserver.TabletServer] DEBUG: ScanSess tid 192.168.11.101:54131 !0
5 entries in 0.01 secs, nbTimes = [5 5 5.00 1]
2015-05-28 02:36:45,942 [Audit] INFO : operation: permitted; user: root; client: 192.168.11.101:53625;
2015-05-28 02:36:45,971 [tablet.Tablet] DEBUG: got [] for logs for y<<
2015-05-28 02:36:46,050 [tablet.Tablet] DEBUG: Reloading constraints for extent: y<<
2015-05-28 02:36:46,064 [constraints.ConstraintChecker] DEBUG: Loaded constraint org.apache.accumulo.core.constraints.DefaultKeySizeConstraint
for y
2015-05-28 02:36:46,064 [constraints.ConstraintChecker] DEBUG: Loaded constraint org.apache.accumulo.examples.simple.constraints.NumericValueConstraint
for y
2015-05-28 02:36:46,072 [tablet.Tablet] TABLET_HIST: y<< opened

2015-05-28 02:38:21,678 [tablet.Tablet] DEBUG: initiateClose(saveState=false queueMinC=false
disableWrites=false) y<<
2015-05-28 02:38:21,678 [tablet.Tablet] DEBUG: completeClose(saveState=false completeClose=true)
y<<
2015-05-28 02:38:21,679 [tserver.NativeMap] DEBUG: Deallocating native map 0x00007fb68c55e410
2015-05-28 02:38:21,680 [tablet.Tablet] TABLET_HIST: y<< closed
2015-05-28 02:38:21,681 [tserver.TabletServer] DEBUG: Unassigning y<<@(null,hostname:33602[14d97f20c900002],null)
2015-05-28 02:38:21,687 [tserver.TabletServer] INFO : Adding 1 logs for extent !0;~< as
alias 1
2015-05-28 02:38:21,721 [tserver.TabletServer] INFO : unloaded y<<
{noformat}

The same situation, but the server missed a constraint removal instead of an addition. The
tabletserver saw 2 constraints , but never got the removal of the NumericValueConstraint the
client sent, so the test ultimately failed when the update was never accepted.

> TabletServer never acknowledged constraint
> ------------------------------------------
>
>                 Key: ACCUMULO-3859
>                 URL: https://issues.apache.org/jira/browse/ACCUMULO-3859
>             Project: Accumulo
>          Issue Type: Bug
>          Components: tserver
>            Reporter: Josh Elser
>            Assignee: Josh Elser
>             Fix For: 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