hadoop-common-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Steve Loughran (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (HADOOP-15003) Merge S3A committers into trunk: Yetus patch checker
Date Mon, 20 Nov 2017 15:38:01 GMT

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

Steve Loughran commented on HADOOP-15003:
-----------------------------------------

Test failure looks legit & presumably concurrency; managed to replicate by significantly
increasing the #of threads and tasks

{code}
2017-11-20 15:30:41,309 [testFailFastCallRevertSuppressed[3]-pool-0] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='failing committer', count=1, limit=8, item=Item{id=1,
committed=true, aborted=false, reverted=false, text=With 8 threads}}: Item{id=1, committed=false,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=1, committed=true, aborted=false,
reverted=false, text=With 8 threads}
2017-11-20 15:30:41,309 [testFailFastCallRevertSuppressed[3]-pool-1] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='failing committer', count=2, limit=8, item=Item{id=2,
committed=true, aborted=false, reverted=false, text=With 8 threads}}: Item{id=2, committed=false,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=2, committed=true, aborted=false,
reverted=false, text=With 8 threads}
2017-11-20 15:30:41,309 [testFailFastCallRevertSuppressed[3]-pool-2] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='failing committer', count=3, limit=8, item=Item{id=3,
committed=true, aborted=false, reverted=false, text=With 8 threads}}: Item{id=3, committed=false,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=3, committed=true, aborted=false,
reverted=false, text=With 8 threads}
2017-11-20 15:30:41,309 [testFailFastCallRevertSuppressed[3]-pool-3] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='failing committer', count=4, limit=8, item=Item{id=4,
committed=true, aborted=false, reverted=false, text=With 8 threads}}: Item{id=4, committed=false,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=4, committed=true, aborted=false,
reverted=false, text=With 8 threads}
2017-11-20 15:30:41,309 [testFailFastCallRevertSuppressed[3]-pool-4] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='failing committer', count=5, limit=8, item=Item{id=5,
committed=true, aborted=false, reverted=false, text=With 8 threads}}: Item{id=5, committed=false,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=5, committed=true, aborted=false,
reverted=false, text=With 8 threads}
2017-11-20 15:30:41,310 [testFailFastCallRevertSuppressed[3]-pool-5] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='failing committer', count=6, limit=8, item=Item{id=6,
committed=true, aborted=false, reverted=false, text=With 8 threads}}: Item{id=6, committed=false,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=6, committed=true, aborted=false,
reverted=false, text=With 8 threads}
2017-11-20 15:30:41,310 [testFailFastCallRevertSuppressed[3]-pool-6] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='failing committer', count=7, limit=8, item=Item{id=7,
committed=true, aborted=false, reverted=false, text=With 8 threads}}: Item{id=7, committed=false,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=7, committed=true, aborted=false,
reverted=false, text=With 8 threads}
2017-11-20 15:30:41,310 [testFailFastCallRevertSuppressed[3]-pool-0] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='failing committer', count=8, limit=8, item=Item{id=9,
committed=true, aborted=false, reverted=false, text=With 8 threads}}: Item{id=9, committed=false,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=9, committed=true, aborted=false,
reverted=false, text=With 8 threads}
2017-11-20 15:30:41,310 [testFailFastCallRevertSuppressed[3]-pool-5] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='failing committer', count=15, limit=8, item=Item{id=15,
committed=true, aborted=false, reverted=false, text=With 8 threads}}: Item{id=15, committed=false,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=15, committed=true, aborted=false,
reverted=false, text=With 8 threads}
2017-11-20 15:30:41,310 [testFailFastCallRevertSuppressed[3]-pool-4] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='failing committer', count=14, limit=8, item=Item{id=14,
committed=true, aborted=false, reverted=false, text=With 8 threads}}: Item{id=14, committed=false,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=14, committed=true, aborted=false,
reverted=false, text=With 8 threads}
2017-11-20 15:30:41,310 [testFailFastCallRevertSuppressed[3]-pool-3] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='failing committer', count=13, limit=8, item=Item{id=13,
committed=true, aborted=false, reverted=false, text=With 8 threads}}: Item{id=13, committed=false,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=13, committed=true, aborted=false,
reverted=false, text=With 8 threads}
2017-11-20 15:30:41,310 [testFailFastCallRevertSuppressed[3]-pool-6] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='failing committer', count=12, limit=8, item=Item{id=12,
committed=true, aborted=false, reverted=false, text=With 8 threads}}: Item{id=12, committed=false,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=12, committed=true, aborted=false,
reverted=false, text=With 8 threads}
2017-11-20 15:30:41,310 [testFailFastCallRevertSuppressed[3]-pool-2] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='failing committer', count=11, limit=8, item=Item{id=12,
committed=true, aborted=false, reverted=false, text=With 8 threads}}: Item{id=11, committed=false,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=11, committed=true, aborted=false,
reverted=false, text=With 8 threads}
2017-11-20 15:30:41,310 [testFailFastCallRevertSuppressed[3]-pool-7] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='failing committer', count=10, limit=8, item=Item{id=11,
committed=true, aborted=false, reverted=false, text=With 8 threads}}: Item{id=8, committed=false,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=8, committed=true, aborted=false,
reverted=false, text=With 8 threads}
2017-11-20 15:30:41,310 [testFailFastCallRevertSuppressed[3]-pool-1] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='failing committer', count=9, limit=8, item=Item{id=10,
committed=true, aborted=false, reverted=false, text=With 8 threads}}: Item{id=10, committed=false,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=10, committed=true, aborted=false,
reverted=false, text=With 8 threads}

/** this is the failing task */
2017-11-20 15:30:41,310 [testFailFastCallRevertSuppressed[3]-pool-5] INFO  commit.Tasks (Tasks.java:run(287))
- Aborting task
2017-11-20 15:30:41,310 [testFailFastCallRevertSuppressed[3]-pool-0] INFO  commit.Tasks (Tasks.java:run(263))
- Task failed
java.io.IOException: BaseCounter{name='failing committer', count=15, limit=8, item=Item{id=15,
committed=true, aborted=false, reverted=false, text=With 8 threads}}: Limit 8 reached for
Item{id=9, committed=true, aborted=false, reverted=false, text=With 8 threads}
	at org.apache.hadoop.fs.s3a.commit.TestTasks$BaseCounter.process(TestTasks.java:460)
	at org.apache.hadoop.fs.s3a.commit.TestTasks$CounterTask.run(TestTasks.java:509)
	at org.apache.hadoop.fs.s3a.commit.TestTasks$CounterTask.run(TestTasks.java:499)
	at org.apache.hadoop.fs.s3a.commit.Tasks$Builder$1.run(Tasks.java:254)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)
2017-11-20 15:30:41,310 [testFailFastCallRevertSuppressed[3]-pool-5] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='aborter', count=1, limit=0, item=Item{id=16,
committed=false, aborted=true, reverted=false, text=With 8 threads}}: Item{id=16, committed=false,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=16, committed=false, aborted=true,
reverted=false, text=With 8 threads}

/* this is task ID #9 still being executed */

2017-11-20 15:30:41,311 [testFailFastCallRevertSuppressed[3]-pool-0] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='failures', count=1, limit=0, item=Item{id=9,
committed=true, aborted=false, reverted=false, text=With 8 threads}}: Item{id=9, committed=true,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=9, committed=true, aborted=false,
reverted=false, text=With 8 threads}

/* reverter starts, but only has 14 successful tasks: it hasn't picked up #9 yet */

2017-11-20 15:30:41,321 [JUnit-testFailFastCallRevertSuppressed[3]] INFO  commit.Tasks (Tasks.java:runParallel(309))
- Reverting all 14 succeeded tasks
2017-11-20 15:30:41,322 [testFailFastCallRevertSuppressed[3]-pool-4] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='reverter', count=1, limit=0, item=Item{id=1,
committed=true, aborted=false, reverted=true, text=With 8 threads}}: Item{id=1, committed=true,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=1, committed=true, aborted=false,
reverted=true, text=With 8 threads}
2017-11-20 15:30:41,322 [testFailFastCallRevertSuppressed[3]-pool-2] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='reverter', count=4, limit=0, item=Item{id=4,
committed=true, aborted=false, reverted=true, text=With 8 threads}}: Item{id=4, committed=true,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=4, committed=true, aborted=false,
reverted=true, text=With 8 threads}
2017-11-20 15:30:41,322 [testFailFastCallRevertSuppressed[3]-pool-6] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='reverter', count=3, limit=0, item=Item{id=3,
committed=true, aborted=false, reverted=true, text=With 8 threads}}: Item{id=3, committed=true,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=3, committed=true, aborted=false,
reverted=true, text=With 8 threads}
2017-11-20 15:30:41,322 [testFailFastCallRevertSuppressed[3]-pool-3] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='reverter', count=2, limit=0, item=Item{id=2,
committed=true, aborted=false, reverted=true, text=With 8 threads}}: Item{id=2, committed=true,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=2, committed=true, aborted=false,
reverted=true, text=With 8 threads}
2017-11-20 15:30:41,322 [testFailFastCallRevertSuppressed[3]-pool-6] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='reverter', count=11, limit=0, item=Item{id=12,
committed=true, aborted=false, reverted=true, text=With 8 threads}}: Item{id=12, committed=true,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=12, committed=true, aborted=false,
reverted=true, text=With 8 threads}
2017-11-20 15:30:41,322 [testFailFastCallRevertSuppressed[3]-pool-2] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='reverter', count=10, limit=0, item=Item{id=13,
committed=true, aborted=false, reverted=true, text=With 8 threads}}: Item{id=13, committed=true,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=13, committed=true, aborted=false,
reverted=true, text=With 8 threads}
2017-11-20 15:30:41,322 [testFailFastCallRevertSuppressed[3]-pool-0] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='reverter', count=9, limit=0, item=Item{id=14,
committed=true, aborted=false, reverted=true, text=With 8 threads}}: Item{id=14, committed=true,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=14, committed=true, aborted=false,
reverted=true, text=With 8 threads}
2017-11-20 15:30:41,322 [testFailFastCallRevertSuppressed[3]-pool-5] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='reverter', count=8, limit=0, item=Item{id=7,
committed=true, aborted=false, reverted=true, text=With 8 threads}}: Item{id=7, committed=true,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=7, committed=true, aborted=false,
reverted=true, text=With 8 threads}
2017-11-20 15:30:41,322 [testFailFastCallRevertSuppressed[3]-pool-7] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='reverter', count=6, limit=0, item=Item{id=6,
committed=true, aborted=false, reverted=true, text=With 8 threads}}: Item{id=5, committed=true,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=5, committed=true, aborted=false,
reverted=true, text=With 8 threads}
2017-11-20 15:30:41,322 [testFailFastCallRevertSuppressed[3]-pool-4] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='reverter', count=7, limit=0, item=Item{id=7,
committed=true, aborted=false, reverted=true, text=With 8 threads}}: Item{id=15, committed=true,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=15, committed=true, aborted=false,
reverted=true, text=With 8 threads}
2017-11-20 15:30:41,322 [testFailFastCallRevertSuppressed[3]-pool-1] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='reverter', count=6, limit=0, item=Item{id=6,
committed=true, aborted=false, reverted=true, text=With 8 threads}}: Item{id=6, committed=true,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=6, committed=true, aborted=false,
reverted=true, text=With 8 threads}
2017-11-20 15:30:41,322 [testFailFastCallRevertSuppressed[3]-pool-2] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='reverter', count=14, limit=0, item=Item{id=10,
committed=true, aborted=false, reverted=true, text=With 8 threads}}: Item{id=10, committed=true,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=10, committed=true, aborted=false,
reverted=true, text=With 8 threads}
2017-11-20 15:30:41,322 [testFailFastCallRevertSuppressed[3]-pool-6] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='reverter', count=13, limit=0, item=Item{id=8,
committed=true, aborted=false, reverted=true, text=With 8 threads}}: Item{id=8, committed=true,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=8, committed=true, aborted=false,
reverted=true, text=With 8 threads}
2017-11-20 15:30:41,322 [testFailFastCallRevertSuppressed[3]-pool-3] INFO  commit.TestTasks
(TestTasks.java:process(458)) - BaseCounter{name='reverter', count=12, limit=0, item=Item{id=11,
committed=true, aborted=false, reverted=true, text=With 8 threads}}: Item{id=11, committed=true,
aborted=false, reverted=false, text=With 8 threads} -> Item{id=11, committed=true, aborted=false,
reverted=true, text=With 8 threads}

/* so the assertion: "all committed tasks were reverted " doesn't hold. */
java.lang.AssertionError: Item{id=9, committed=true, aborted=false, reverted=false, text=With
8 threads} was not reverted in [Item{id=1, committed=true, aborted=false, reverted=true, text=With
8 threads}
Item{id=2, committed=true, aborted=false, reverted=true, text=With 8 threads}
Item{id=3, committed=true, aborted=false, reverted=true, text=With 8 threads}
Item{id=4, committed=true, aborted=false, reverted=true, text=With 8 threads}
Item{id=5, committed=true, aborted=false, reverted=true, text=With 8 threads}
Item{id=6, committed=true, aborted=false, reverted=true, text=With 8 threads}
Item{id=7, committed=true, aborted=false, reverted=true, text=With 8 threads}
Item{id=8, committed=true, aborted=false, reverted=true, text=With 8 threads}
Item{id=9, committed=true, aborted=false, reverted=false, text=With 8 threads}
Item{id=10, committed=true, aborted=false, reverted=true, text=With 8 threads}
Item{id=11, committed=true, aborted=false, reverted=true, text=With 8 threads}
Item{id=12, committed=true, aborted=false, reverted=true, text=With 8 threads}
Item{id=13, committed=true, aborted=false, reverted=true, text=With 8 threads}
Item{id=14, committed=true, aborted=false, reverted=true, text=With 8 threads}
Item{id=15, committed=true, aborted=false, reverted=true, text=With 8 threads}
Item{id=16, committed=false, aborted=true, reverted=false, text=With 8 threads}]

	at org.junit.Assert.fail(Assert.java:88)
	at org.junit.Assert.assertTrue(Assert.java:41)
	at org.apache.hadoop.fs.s3a.commit.TestTasks$Item.assertReverted(TestTasks.java:402)
	at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:184)
	at java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:175)
	at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1374)
	at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:481)
	at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:471)
	at java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:151)
	at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:174)
	at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
	at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:418)
	at org.apache.hadoop.fs.s3a.commit.TestTasks.testFailFastCallRevertSuppressed(TestTasks.java:231)
	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:498)
	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)
{code}



> Merge S3A committers into trunk: Yetus patch checker
> ----------------------------------------------------
>
>                 Key: HADOOP-15003
>                 URL: https://issues.apache.org/jira/browse/HADOOP-15003
>             Project: Hadoop Common
>          Issue Type: Sub-task
>          Components: fs/s3
>    Affects Versions: 3.0.0
>            Reporter: Steve Loughran
>            Assignee: Steve Loughran
>         Attachments: HADOOP-13786-041.patch, HADOOP-13786-042.patch, HADOOP-13786-043.patch,
HADOOP-13786-044.patch, HADOOP-13786-045.patch, HADOOP-13786-046.patch, HADOOP-13786-047.patch,
HADOOP-13786-048.patch, HADOOP-13786-049.patch, HADOOP-13786-050.patch, HADOOP-13786-051.patch,
HADOOP-15033-testfix-1.diff
>
>
> This is a Yetus only JIRA created to have Yetus review the HADOOP-13786/HADOOP-14971
patch as a .patch file, as the review PR [https://github.com/apache/hadoop/pull/282] is stopping
this happening in HADOOP-14971.
> Reviews should go into the PR/other task



--
This message was sent by Atlassian JIRA
(v6.4.14#64029)

---------------------------------------------------------------------
To unsubscribe, e-mail: common-issues-unsubscribe@hadoop.apache.org
For additional commands, e-mail: common-issues-help@hadoop.apache.org


Mime
View raw message