[
https://issues.apache.org/jira/browse/TEPHRA-253?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16160061#comment-16160061
]
Andreas Neumann commented on TEPHRA-253:
----------------------------------------
Suspicion confirmed. After changing travis to dump the standard output of the
test case, I see:
{noformat}
2017-09-09 19:18:16,851 - INFO [main:o.a.h.h.r.RegionCoprocessorHost@196] -
Load coprocessor org.apache.tephra.hbase.coprocessor.TransactionProcessor from
HTD of TestRegionScanner successfully.
2017-09-09 19:18:16,868 - INFO
[StoreOpener-fc704aec719b675f06e5d7bd12da85f0-1:o.a.h.h.r.c.CompactionConfiguration@85]
- size [134217728, 9223372036854775807); files [3, 10); ratio 1.200000;
off-peak ratio 5.000000; throttle point 2684354560; delete expired; major
period 604800000, major jitter 0.500000
2017-09-09 19:18:16,883 - INFO [main:o.a.h.h.r.HRegion@644] - Onlined
fc704aec719b675f06e5d7bd12da85f0; next sequenceid=1
2017-09-09 19:18:16,883 - INFO [main:o.a.t.h.c.TransactionProcessorTest@178] -
Coprocessor is using transaction state: null
2017-09-09 19:18:16,926 - INFO [main:o.a.t.h.c.TransactionProcessorTest@192] -
Flushing region
TestRegionScanner,,1504984696824.fc704aec719b675f06e5d7bd12da85f0.
2017-09-09 19:18:16,960 - INFO [HDFSTransactionStateStorage
STARTING:o.a.t.p.HDFSTransactionStateStorage@109] - Using snapshot dir
/home/travis/build/apache/incubator-tephra/tephra-hbase-compat-0.96/target/junit6493752557205114158/junit8165179254738335598
2017-09-09 19:18:16,981 - INFO [TransactionStateCache
STARTING:o.a.t.p.HDFSTransactionStateStorage@185] - Read encoded transaction
snapshot of 84 bytes
2017-09-09 19:18:16,984 - INFO [TransactionStateCache
STARTING:o.a.t.c.TransactionStateCache@166] - Transaction state reloaded with
snapshot from 1504984695267
2017-09-09 19:18:17,393 - INFO [main:o.a.h.h.r.DefaultStoreFlusher@88] -
Flushed, sequenceid=37, memsize=5.9 K, hasBloomFilter=true, into tmp file
hdfs://localhost:53322/home/travis/build/apache/incubator-tephra/tephra-hbase-compat-0.96/target/junit6493752557205114158/junit7077794411994061305/hbase/data/default/TestRegionScanner/fc704aec719b675f06e5d7bd12da85f0/.tmp/6e813e3b7af94e13afc9dc1303dda3f8
2017-09-09 19:18:17,415 - INFO [main:o.a.h.h.r.HStore@770] - Added
hdfs://localhost:53322/home/travis/build/apache/incubator-tephra/tephra-hbase-compat-0.96/target/junit6493752557205114158/junit7077794411994061305/hbase/data/default/TestRegionScanner/fc704aec719b675f06e5d7bd12da85f0/f/6e813e3b7af94e13afc9dc1303dda3f8,
entries=36, sequenceid=37, filesize=2.2 K
2017-09-09 19:18:17,416 - INFO [main:o.a.h.h.r.HRegion@1708] - Finished
memstore flush of ~5.9 K/6048, currentsize=0/0 for region
TestRegionScanner,,1504984696824.fc704aec719b675f06e5d7bd12da85f0. in 489ms,
sequenceid=37, compaction requested=false
{noformat}
Clearly, the flush begins before the transaction state is loaded.
> TransactionProcessorTest is sometimes flaky
> -------------------------------------------
>
> Key: TEPHRA-253
> URL: https://issues.apache.org/jira/browse/TEPHRA-253
> Project: Tephra
> Issue Type: Bug
> Affects Versions: 0.12.0-incubating
> Reporter: Andreas Neumann
> Assignee: Andreas Neumann
> Fix For: 0.13.0-incubating
>
>
> The test sometimes fails as follows:
> {noformat}
> Running org.apache.tephra.hbase.coprocessor.TransactionProcessorTest
> Tests run: 6, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 7.741 sec <<<
> FAILURE!
> testFamilyDeleteTimestamp(org.apache.tephra.hbase.coprocessor.TransactionProcessorTest)
> Time elapsed: 1.526 sec
> testTransactionStateCache(org.apache.tephra.hbase.coprocessor.TransactionProcessorTest)
> Time elapsed: 0.053 sec
> testDataJanitorRegionScanner(org.apache.tephra.hbase.coprocessor.TransactionProcessorTest)
> Time elapsed: 0.288 sec <<< FAILURE!
> org.junit.internal.ArrayComparisonFailure: arrays first differed at element
> [3]; expected:<4> but was:<1>
> at
> org.junit.internal.ComparisonCriteria.arrayEquals(ComparisonCriteria.java:50)
> at org.junit.Assert.internalArrayEquals(Assert.java:473)
> at org.junit.Assert.assertArrayEquals(Assert.java:294)
> at org.junit.Assert.assertArrayEquals(Assert.java:305)
> at
> org.apache.tephra.hbase.coprocessor.TransactionProcessorTest.assertKeyValueMatches(TransactionProcessorTest.java:593)
> at
> org.apache.tephra.hbase.coprocessor.TransactionProcessorTest.assertKeyValueMatches(TransactionProcessorTest.java:585)
> at
> org.apache.tephra.hbase.coprocessor.TransactionProcessorTest.testDataJanitorRegionScanner(TransactionProcessorTest.java:190)
> {noformat}
> It is not clear what is causing this, most likely the region server did not
> have an up-to-date transaction state snapshot at the time of the lfush (that
> might be due to TEPHRA-239 orTEPHRA-249, or it might be a condition where
> flush() has no effect because the region is already flushing,
> Let's observe this and gather more information when/if it happens again.
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
