hbase-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Ted Yu (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (HBASE-6928) TestStoreFile sometimes fails with 'Column family prefix used twice'
Date Tue, 02 Oct 2012 23:55:07 GMT

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

Ted Yu commented on HBASE-6928:
-------------------------------

Here was test output:
{code}
Stacktrace

java.lang.AssertionError: Column family prefix used twice: cf.cf.bt.Data.fsReadnumops
	at org.apache.hadoop.hbase.regionserver.metrics.SchemaMetrics.validateMetricChanges(SchemaMetrics.java:822)
	at org.apache.hadoop.hbase.regionserver.TestStoreFile.tearDown(TestStoreFile.java:89)
	at junit.framework.TestCase.runBare(TestCase.java:140)
	at junit.framework.TestResult$1.protect(TestResult.java:110)
	at junit.framework.TestResult.runProtected(TestResult.java:128)
	at junit.framework.TestResult.run(TestResult.java:113)
	at junit.framework.TestCase.run(TestCase.java:124)
	at junit.framework.TestSuite.runTest(TestSuite.java:243)
	at junit.framework.TestSuite.run(TestSuite.java:238)
	at org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:83)
	at org.junit.runners.Suite.runChild(Suite.java:128)
	at org.junit.runners.Suite.runChild(Suite.java:24)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:722)

Standard Output

2012-10-02 18:20:55,362 INFO  [pool-1-thread-1] hbase.ResourceChecker(139): before: regionserver.TestStoreFile#testMultipleTimestamps Thread=59, OpenFileDescriptor=102, MaxFileDescriptor=1024, ConnectionCount=0
2012-10-02 18:20:55,368 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.log.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/71953882-044e-4058-9443-27c873ad3357
2012-10-02 18:20:55,374 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.log.dir property value differs in configuration and system: Configuration=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/../logs while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir Erasing configuration value by system value.
2012-10-02 18:20:55,374 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.tmp.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/71953882-044e-4058-9443-27c873ad3357
2012-10-02 18:20:55,374 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.tmp.dir property value differs in configuration and system: Configuration=/tmp/hadoop-hudson while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir Erasing configuration value by system value.
2012-10-02 18:20:55,374 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("mapred.working.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/mapred-working-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/71953882-044e-4058-9443-27c873ad3357
2012-10-02 18:20:55,383 DEBUG [pool-1-thread-1] util.FSUtils(167): Creating file=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/71953882-044e-4058-9443-27c873ad3357/testMultipleTimestamps/regionname/familyname/1234567890/34f0c9be641d459abb09e325d5414cf3 with permission=rwxrwxrwx
2012-10-02 18:20:55,383 DEBUG [pool-1-thread-1] hfile.HFileWriterV2(142): Initialized with CacheConfig:enabled [cacheDataOnRead=true] [cacheDataOnWrite=false] [cacheIndexesOnWrite=false] [cacheBloomsOnWrite=false] [cacheEvictOnClose=false] [cacheCompressed=false]
2012-10-02 18:20:55,384 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1051): Delete Family Bloom filter type for /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/71953882-044e-4058-9443-27c873ad3357/testMultipleTimestamps/regionname/familyname/1234567890/34f0c9be641d459abb09e325d5414cf3: CompoundBloomFilterWriter
2012-10-02 18:20:55,384 INFO  [pool-1-thread-1] regionserver.TestStoreFile(703): 
2012-10-02 18:20:55,384 INFO  [pool-1-thread-1] regionserver.TestStoreFile(704): 
2012-10-02 18:20:55,384 INFO  [pool-1-thread-1] regionserver.TestStoreFile(703): 
2012-10-02 18:20:55,384 INFO  [pool-1-thread-1] regionserver.TestStoreFile(704): 
2012-10-02 18:20:55,384 INFO  [pool-1-thread-1] regionserver.TestStoreFile(703): 
2012-10-02 18:20:55,384 INFO  [pool-1-thread-1] regionserver.TestStoreFile(704): 
2012-10-02 18:20:55,384 INFO  [pool-1-thread-1] regionserver.TestStoreFile(703): 
2012-10-02 18:20:55,384 INFO  [pool-1-thread-1] regionserver.TestStoreFile(704): 
2012-10-02 18:20:55,384 INFO  [pool-1-thread-1] regionserver.TestStoreFile(703): 
2012-10-02 18:20:55,384 INFO  [pool-1-thread-1] regionserver.TestStoreFile(704): 
2012-10-02 18:20:55,384 INFO  [pool-1-thread-1] regionserver.TestStoreFile(703): 
2012-10-02 18:20:55,384 INFO  [pool-1-thread-1] regionserver.TestStoreFile(704): 
2012-10-02 18:20:55,385 INFO  [pool-1-thread-1] regionserver.TestStoreFile(703): 
2012-10-02 18:20:55,385 INFO  [pool-1-thread-1] regionserver.TestStoreFile(704): 
2012-10-02 18:20:55,385 INFO  [pool-1-thread-1] regionserver.TestStoreFile(703): 
2012-10-02 18:20:55,385 INFO  [pool-1-thread-1] regionserver.TestStoreFile(704): 
2012-10-02 18:20:55,385 INFO  [pool-1-thread-1] regionserver.TestStoreFile(703): 	
2012-10-02 18:20:55,385 INFO  [pool-1-thread-1] regionserver.TestStoreFile(704): 	
2012-10-02 18:20:55,385 INFO  [pool-1-thread-1] regionserver.TestStoreFile(703): 

2012-10-02 18:20:55,385 INFO  [pool-1-thread-1] regionserver.TestStoreFile(704): 

2012-10-02 18:20:55,385 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1271): NO General Bloom and NO DeleteFamily was added to HFile (/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/71953882-044e-4058-9443-27c873ad3357/testMultipleTimestamps/regionname/familyname/1234567890/34f0c9be641d459abb09e325d5414cf3) 
2012-10-02 18:20:55,446 INFO  [pool-1-thread-1] hbase.ResourceChecker(157): after: regionserver.TestStoreFile#testMultipleTimestamps Thread=59 (was 59), OpenFileDescriptor=104 (was 102) - OpenFileDescriptor LEAK? -, MaxFileDescriptor=1024 (was 1024), ConnectionCount=0 (was 0)
2012-10-02 18:20:55,447 INFO  [pool-1-thread-1] hbase.ResourceChecker(139): before: regionserver.TestStoreFile#testBloomEdgeCases Thread=59, OpenFileDescriptor=104, MaxFileDescriptor=1024, ConnectionCount=0
2012-10-02 18:20:55,454 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.log.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/864e389e-ada8-499f-b2dd-7884712ebca7
2012-10-02 18:20:55,459 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.log.dir property value differs in configuration and system: Configuration=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/../logs while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir Erasing configuration value by system value.
2012-10-02 18:20:55,460 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.tmp.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/864e389e-ada8-499f-b2dd-7884712ebca7
2012-10-02 18:20:55,460 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.tmp.dir property value differs in configuration and system: Configuration=/tmp/hadoop-hudson while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir Erasing configuration value by system value.
2012-10-02 18:20:55,460 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("mapred.working.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/mapred-working-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/864e389e-ada8-499f-b2dd-7884712ebca7
2012-10-02 18:20:55,468 DEBUG [pool-1-thread-1] util.FSUtils(167): Creating file=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testBloomEdgeCases with permission=rwxrwxrwx
2012-10-02 18:20:55,470 DEBUG [pool-1-thread-1] util.BloomFilterFactory(224): Skipping bloom filter because max keysize too large: 2000
2012-10-02 18:20:55,470 INFO  [pool-1-thread-1] util.BloomFilterFactory(263): Delete Family Bloom filter is not supported in HFile V1
2012-10-02 18:20:55,470 INFO  [pool-1-thread-1] hfile.HFileWriterV1(371): Wrote a version 1 block index with 0 keys
2012-10-02 18:20:55,470 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1271): NO General Bloom and NO DeleteFamily was added to HFile (/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testBloomEdgeCases) 
2012-10-02 18:20:55,471 DEBUG [pool-1-thread-1] util.FSUtils(167): Creating file=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testBloomEdgeCases with permission=rwxrwxrwx
2012-10-02 18:20:55,486 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1034): Bloom filter type for /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testBloomEdgeCases: ROW, ByteBloomFilter
2012-10-02 18:20:55,486 INFO  [pool-1-thread-1] util.BloomFilterFactory(263): Delete Family Bloom filter is not supported in HFile V1
2012-10-02 18:20:55,537 INFO  [pool-1-thread-1] hfile.HFileWriterV1(371): Wrote a version 1 block index with 6 keys
2012-10-02 18:20:55,537 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1271): General Bloom and NO DeleteFamily was added to HFile (/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testBloomEdgeCases) 
2012-10-02 18:20:55,539 INFO  [pool-1-thread-1] regionserver.StoreFile$Reader(1639): Loaded ROW (ByteBloomFilter) metadata for testBloomEdgeCases
2012-10-02 18:20:55,584 DEBUG [pool-1-thread-1] hfile.HFileReaderV1(387): On close of file testBloomEdgeCases evicted 0 block(s) of 6 total blocks
2012-10-02 18:20:55,585 DEBUG [pool-1-thread-1] util.FSUtils(167): Creating file=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testBloomEdgeCases with permission=rwxrwxrwx
2012-10-02 18:20:55,586 DEBUG [pool-1-thread-1] util.BloomFilterFactory(224): Skipping bloom filter because max keysize too large: 2147483647
2012-10-02 18:20:55,586 INFO  [pool-1-thread-1] util.BloomFilterFactory(263): Delete Family Bloom filter is not supported in HFile V1
2012-10-02 18:20:55,586 INFO  [pool-1-thread-1] hfile.HFileWriterV1(371): Wrote a version 1 block index with 0 keys
2012-10-02 18:20:55,586 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1271): NO General Bloom and NO DeleteFamily was added to HFile (/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testBloomEdgeCases) 
2012-10-02 18:20:55,610 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 2 units of cf.TestStoreFile.MetablockCacheNumCached towards MetablockCacheNumCached
2012-10-02 18:20:55,610 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 2 units of cf.TestStoreFile.bt.Bloom.fsReadnumops towards bt.Bloom.fsReadnumops
2012-10-02 18:20:55,611 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 1327612 units of cf.TestStoreFile.bt.Bloom.fsRead_total towards bt.Bloom.fsRead_total
2012-10-02 18:20:55,611 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 2001 units of cf.TestStoreFile.bt.Bloom.fsBlockReadCnt towards bt.Bloom.fsBlockReadCnt
2012-10-02 18:20:55,611 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 1999 units of cf.TestStoreFile.bt.Bloom.fsBlockReadCacheHitCnt towards bt.Bloom.fsBlockReadCacheHitCnt
2012-10-02 18:20:55,611 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 2 units of cf.TestStoreFile.bt.Bloom.fsBlockReadCacheMissCnt towards bt.Bloom.fsBlockReadCacheMissCnt
2012-10-02 18:20:55,611 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 2 units of cf.TestStoreFile.fsReadnumops towards fsReadnumops
2012-10-02 18:20:55,611 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 1327612 units of cf.TestStoreFile.fsRead_total towards fsRead_total
2012-10-02 18:20:55,611 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 2001 units of cf.TestStoreFile.fsBlockReadCnt towards fsBlockReadCnt
2012-10-02 18:20:55,611 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 1999 units of cf.TestStoreFile.fsBlockReadCacheHitCnt towards fsBlockReadCacheHitCnt
2012-10-02 18:20:55,611 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 2 units of cf.TestStoreFile.fsBlockReadCacheMissCnt towards fsBlockReadCacheMissCnt
2012-10-02 18:20:55,611 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 2 units of cf.TestStoreFile.blockCacheNumCached towards blockCacheNumCached
2012-10-02 18:20:55,611 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 1000 units of cf.TestStoreFile.keyNotInBloomCnt towards keyNotInBloomCnt
2012-10-02 18:20:55,611 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 1000 units of cf.TestStoreFile.keyMaybeInBloomCnt towards keyMaybeInBloomCnt
2012-10-02 18:20:55,625 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=MetablockCacheNumCached, delta=2
2012-10-02 18:20:55,625 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=bt.Bloom.fsReadnumops, delta=2
2012-10-02 18:20:55,625 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=bt.Bloom.fsRead_total, delta=1327612
2012-10-02 18:20:55,625 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=bt.Bloom.fsBlockReadCnt, delta=2001
2012-10-02 18:20:55,625 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=bt.Bloom.fsBlockReadCacheHitCnt, delta=1999
2012-10-02 18:20:55,625 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=bt.Bloom.fsBlockReadCacheMissCnt, delta=2
2012-10-02 18:20:55,625 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=fsReadnumops, delta=2
2012-10-02 18:20:55,625 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=fsRead_total, delta=1327612
2012-10-02 18:20:55,625 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=fsBlockReadCnt, delta=2001
2012-10-02 18:20:55,625 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=fsBlockReadCacheHitCnt, delta=1999
2012-10-02 18:20:55,625 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=fsBlockReadCacheMissCnt, delta=2
2012-10-02 18:20:55,626 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=blockCacheNumCached, delta=2
2012-10-02 18:20:55,626 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=keyNotInBloomCnt, delta=1000
2012-10-02 18:20:55,626 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=keyMaybeInBloomCnt, delta=1000
2012-10-02 18:20:55,649 INFO  [pool-1-thread-1] hbase.ResourceChecker(157): after: regionserver.TestStoreFile#testBloomEdgeCases Thread=59 (was 59), OpenFileDescriptor=104 (was 104), MaxFileDescriptor=1024 (was 1024), ConnectionCount=0 (was 0)
2012-10-02 18:20:55,650 INFO  [pool-1-thread-1] hbase.ResourceChecker(139): before: regionserver.TestStoreFile#testSeqIdComparator Thread=59, OpenFileDescriptor=104, MaxFileDescriptor=1024, ConnectionCount=0
2012-10-02 18:20:55,657 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.log.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/60f8990c-3de9-44dc-8e4c-b275a4e002a6
2012-10-02 18:20:55,663 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.log.dir property value differs in configuration and system: Configuration=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/../logs while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir Erasing configuration value by system value.
2012-10-02 18:20:55,663 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.tmp.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/60f8990c-3de9-44dc-8e4c-b275a4e002a6
2012-10-02 18:20:55,663 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.tmp.dir property value differs in configuration and system: Configuration=/tmp/hadoop-hudson while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir Erasing configuration value by system value.
2012-10-02 18:20:55,663 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("mapred.working.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/mapred-working-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/60f8990c-3de9-44dc-8e4c-b275a4e002a6
2012-10-02 18:20:55,684 DEBUG [pool-1-thread-1] regionserver.TestStoreFile(667): sfs: mock storefile, bulkLoad=true bulkTimestamp=1000 seqId=-1 path=/foo/123,mock storefile, bulkLoad=true bulkTimestamp=1000 seqId=-1 path=/foo/126,mock storefile, bulkLoad=true bulkTimestamp=2000 seqId=-1 path=/foo/126,mock storefile, bulkLoad=false bulkTimestamp=-1 seqId=1 path=/foo/1,mock storefile, bulkLoad=false bulkTimestamp=-1 seqId=3 path=/foo/2,mock storefile, bulkLoad=false bulkTimestamp=-1 seqId=5 path=/foo/2,mock storefile, bulkLoad=false bulkTimestamp=-1 seqId=5 path=/foo/3
2012-10-02 18:20:55,685 DEBUG [pool-1-thread-1] regionserver.TestStoreFile(668): sorted: mock storefile, bulkLoad=true bulkTimestamp=1000 seqId=-1 path=/foo/123,mock storefile, bulkLoad=true bulkTimestamp=1000 seqId=-1 path=/foo/126,mock storefile, bulkLoad=true bulkTimestamp=2000 seqId=-1 path=/foo/126,mock storefile, bulkLoad=false bulkTimestamp=-1 seqId=1 path=/foo/1,mock storefile, bulkLoad=false bulkTimestamp=-1 seqId=3 path=/foo/2,mock storefile, bulkLoad=false bulkTimestamp=-1 seqId=5 path=/foo/2,mock storefile, bulkLoad=false bulkTimestamp=-1 seqId=5 path=/foo/3
2012-10-02 18:20:55,744 INFO  [pool-1-thread-1] hbase.ResourceChecker(157): after: regionserver.TestStoreFile#testSeqIdComparator Thread=59 (was 59), OpenFileDescriptor=104 (was 104), MaxFileDescriptor=1024 (was 1024), ConnectionCount=0 (was 0)
2012-10-02 18:20:55,745 INFO  [pool-1-thread-1] hbase.ResourceChecker(139): before: regionserver.TestStoreFile#testCacheOnWriteEvictOnClose Thread=59, OpenFileDescriptor=104, MaxFileDescriptor=1024, ConnectionCount=0
2012-10-02 18:20:55,752 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.log.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/54d1e999-8e17-419c-ac70-627faa1d4c0a
2012-10-02 18:20:55,758 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.log.dir property value differs in configuration and system: Configuration=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/../logs while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir Erasing configuration value by system value.
2012-10-02 18:20:55,758 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.tmp.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/54d1e999-8e17-419c-ac70-627faa1d4c0a
2012-10-02 18:20:55,758 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.tmp.dir property value differs in configuration and system: Configuration=/tmp/hadoop-hudson while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir Erasing configuration value by system value.
2012-10-02 18:20:55,758 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("mapred.working.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/mapred-working-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/54d1e999-8e17-419c-ac70-627faa1d4c0a
2012-10-02 18:20:55,766 DEBUG [pool-1-thread-1] util.FSUtils(167): Creating file=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/54d1e999-8e17-419c-ac70-627faa1d4c0a/testCacheOnWriteEvictOnClose/regionname/twoCOWEOC/123456789 with permission=rwxrwxrwx
2012-10-02 18:20:55,767 DEBUG [pool-1-thread-1] hfile.HFileWriterV2(142): Initialized with CacheConfig:enabled [cacheDataOnRead=true] [cacheDataOnWrite=false] [cacheIndexesOnWrite=false] [cacheBloomsOnWrite=false] [cacheEvictOnClose=false] [cacheCompressed=false]
2012-10-02 18:20:55,767 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1051): Delete Family Bloom filter type for /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/54d1e999-8e17-419c-ac70-627faa1d4c0a/testCacheOnWriteEvictOnClose/regionname/twoCOWEOC/123456789: CompoundBloomFilterWriter
2012-10-02 18:20:55,768 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1271): NO General Bloom and NO DeleteFamily was added to HFile (/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/54d1e999-8e17-419c-ac70-627faa1d4c0a/testCacheOnWriteEvictOnClose/regionname/twoCOWEOC/123456789) 
2012-10-02 18:20:55,768 DEBUG [pool-1-thread-1] regionserver.TestStoreFile(786): /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/54d1e999-8e17-419c-ac70-627faa1d4c0a/testCacheOnWriteEvictOnClose/regionname/twoCOWEOC/123456789
2012-10-02 18:20:55,770 DEBUG [pool-1-thread-1] util.FSUtils(167): Creating file=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/54d1e999-8e17-419c-ac70-627faa1d4c0a/testCacheOnWriteEvictOnClose/regionname/twoCOWEOC/123456788 with permission=rwxrwxrwx
2012-10-02 18:20:55,771 DEBUG [pool-1-thread-1] hfile.HFileWriterV2(142): Initialized with CacheConfig:enabled [cacheDataOnRead=true] [cacheDataOnWrite=true] [cacheIndexesOnWrite=false] [cacheBloomsOnWrite=false] [cacheEvictOnClose=false] [cacheCompressed=false]
2012-10-02 18:20:55,771 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1051): Delete Family Bloom filter type for /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/54d1e999-8e17-419c-ac70-627faa1d4c0a/testCacheOnWriteEvictOnClose/regionname/twoCOWEOC/123456788: CompoundBloomFilterWriter
2012-10-02 18:20:55,771 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1271): NO General Bloom and NO DeleteFamily was added to HFile (/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/54d1e999-8e17-419c-ac70-627faa1d4c0a/testCacheOnWriteEvictOnClose/regionname/twoCOWEOC/123456788) 
2012-10-02 18:20:55,804 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 3 units of cf.twoCOWEOC.bt.Data.fsReadnumops towards bt.Data.fsReadnumops
2012-10-02 18:20:55,804 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 973274 units of cf.twoCOWEOC.bt.Data.fsRead_total towards bt.Data.fsRead_total
2012-10-02 18:20:55,804 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 12 units of cf.twoCOWEOC.bt.Data.fsBlockReadCnt towards bt.Data.fsBlockReadCnt
2012-10-02 18:20:55,805 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 9 units of cf.twoCOWEOC.bt.Data.fsBlockReadCacheHitCnt towards bt.Data.fsBlockReadCacheHitCnt
2012-10-02 18:20:55,805 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 3 units of cf.twoCOWEOC.bt.Data.fsBlockReadCacheMissCnt towards bt.Data.fsBlockReadCacheMissCnt
2012-10-02 18:20:55,805 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 6 units of cf.twoCOWEOC.bt.Data.blockCacheNumCached towards bt.Data.blockCacheNumCached
2012-10-02 18:20:55,805 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 3 units of cf.twoCOWEOC.bt.Data.blockCacheNumEvicted towards bt.Data.blockCacheNumEvicted
2012-10-02 18:20:55,805 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 3 units of cf.twoCOWEOC.fsReadnumops towards fsReadnumops
2012-10-02 18:20:55,805 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 973274 units of cf.twoCOWEOC.fsRead_total towards fsRead_total
2012-10-02 18:20:55,805 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 12 units of cf.twoCOWEOC.fsBlockReadCnt towards fsBlockReadCnt
2012-10-02 18:20:55,805 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 9 units of cf.twoCOWEOC.fsBlockReadCacheHitCnt towards fsBlockReadCacheHitCnt
2012-10-02 18:20:55,805 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 3 units of cf.twoCOWEOC.fsBlockReadCacheMissCnt towards fsBlockReadCacheMissCnt
2012-10-02 18:20:55,805 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 6 units of cf.twoCOWEOC.blockCacheNumCached towards blockCacheNumCached
2012-10-02 18:20:55,805 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 3 units of cf.twoCOWEOC.blockCacheNumEvicted towards blockCacheNumEvicted
2012-10-02 18:20:55,812 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=bt.Data.fsReadnumops, delta=3
2012-10-02 18:20:55,812 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=bt.Data.fsRead_total, delta=973274
2012-10-02 18:20:55,812 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=bt.Data.fsBlockReadCnt, delta=12
2012-10-02 18:20:55,812 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=bt.Data.fsBlockReadCacheHitCnt, delta=9
2012-10-02 18:20:55,812 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=bt.Data.fsBlockReadCacheMissCnt, delta=3
2012-10-02 18:20:55,813 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=bt.Data.blockCacheNumCached, delta=6
2012-10-02 18:20:55,813 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=bt.Data.blockCacheNumEvicted, delta=3
2012-10-02 18:20:55,813 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=fsReadnumops, delta=3
2012-10-02 18:20:55,813 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=fsRead_total, delta=973274
2012-10-02 18:20:55,813 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=fsBlockReadCnt, delta=12
2012-10-02 18:20:55,813 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=fsBlockReadCacheHitCnt, delta=9
2012-10-02 18:20:55,813 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=fsBlockReadCacheMissCnt, delta=3
2012-10-02 18:20:55,813 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=blockCacheNumCached, delta=6
2012-10-02 18:20:55,813 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=blockCacheNumEvicted, delta=3
2012-10-02 18:20:55,834 INFO  [pool-1-thread-1] hbase.ResourceChecker(157): after: regionserver.TestStoreFile#testCacheOnWriteEvictOnClose Thread=59 (was 59), OpenFileDescriptor=104 (was 104), MaxFileDescriptor=1024 (was 1024), ConnectionCount=0 (was 0)
2012-10-02 18:20:55,835 INFO  [pool-1-thread-1] hbase.ResourceChecker(139): before: regionserver.TestStoreFile#testDataBlockEncodingMetaData Thread=59, OpenFileDescriptor=104, MaxFileDescriptor=1024, ConnectionCount=0
2012-10-02 18:20:55,842 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.log.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/f74aa46e-9b5a-4556-aee3-ea002b263c46
2012-10-02 18:20:55,847 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.log.dir property value differs in configuration and system: Configuration=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/../logs while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir Erasing configuration value by system value.
2012-10-02 18:20:55,847 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.tmp.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/f74aa46e-9b5a-4556-aee3-ea002b263c46
2012-10-02 18:20:55,847 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.tmp.dir property value differs in configuration and system: Configuration=/tmp/hadoop-hudson while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir Erasing configuration value by system value.
2012-10-02 18:20:55,848 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("mapred.working.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/mapred-working-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/f74aa46e-9b5a-4556-aee3-ea002b263c46
2012-10-02 18:20:55,855 DEBUG [pool-1-thread-1] util.FSUtils(167): Creating file=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/f74aa46e-9b5a-4556-aee3-ea002b263c46/testDataBlockEncodingMetaData/regionname/familyname/1234567890 with permission=rwxrwxrwx
2012-10-02 18:20:55,856 DEBUG [pool-1-thread-1] hfile.HFileWriterV2(142): Initialized with CacheConfig:enabled [cacheDataOnRead=true] [cacheDataOnWrite=false] [cacheIndexesOnWrite=false] [cacheBloomsOnWrite=false] [cacheEvictOnClose=false] [cacheCompressed=false]
2012-10-02 18:20:55,856 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1051): Delete Family Bloom filter type for /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/f74aa46e-9b5a-4556-aee3-ea002b263c46/testDataBlockEncodingMetaData/regionname/familyname/1234567890: CompoundBloomFilterWriter
2012-10-02 18:20:55,857 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1271): NO General Bloom and NO DeleteFamily was added to HFile (/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/f74aa46e-9b5a-4556-aee3-ea002b263c46/testDataBlockEncodingMetaData/regionname/familyname/1234567890) 
2012-10-02 18:20:55,913 INFO  [pool-1-thread-1] hbase.ResourceChecker(157): after: regionserver.TestStoreFile#testDataBlockEncodingMetaData Thread=59 (was 59), OpenFileDescriptor=106 (was 104) - OpenFileDescriptor LEAK? -, MaxFileDescriptor=1024 (was 1024), ConnectionCount=0 (was 0)
2012-10-02 18:20:55,914 INFO  [pool-1-thread-1] hbase.ResourceChecker(139): before: regionserver.TestStoreFile#testBasicHalfMapFile Thread=59, OpenFileDescriptor=106, MaxFileDescriptor=1024, ConnectionCount=0
2012-10-02 18:20:55,921 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.log.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/13883334-71f4-4de2-9fd1-10cae4ccd87e
2012-10-02 18:20:55,926 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.log.dir property value differs in configuration and system: Configuration=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/../logs while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir Erasing configuration value by system value.
2012-10-02 18:20:55,926 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.tmp.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/13883334-71f4-4de2-9fd1-10cae4ccd87e
2012-10-02 18:20:55,927 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.tmp.dir property value differs in configuration and system: Configuration=/tmp/hadoop-hudson while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir Erasing configuration value by system value.
2012-10-02 18:20:55,927 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("mapred.working.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/mapred-working-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/13883334-71f4-4de2-9fd1-10cae4ccd87e
2012-10-02 18:20:55,942 DEBUG [pool-1-thread-1] util.FSUtils(167): Creating file=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/13883334-71f4-4de2-9fd1-10cae4ccd87e/testBasicHalfMapFile/regionname/familyname/c30e08a4e3ed48bbbe1ed255d7da0c6e with permission=rwxrwxrwx
2012-10-02 18:20:55,943 DEBUG [pool-1-thread-1] hfile.HFileWriterV2(142): Initialized with CacheConfig:enabled [cacheDataOnRead=true] [cacheDataOnWrite=false] [cacheIndexesOnWrite=false] [cacheBloomsOnWrite=false] [cacheEvictOnClose=false] [cacheCompressed=false]
2012-10-02 18:20:55,943 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1051): Delete Family Bloom filter type for /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/13883334-71f4-4de2-9fd1-10cae4ccd87e/testBasicHalfMapFile/regionname/familyname/c30e08a4e3ed48bbbe1ed255d7da0c6e: CompoundBloomFilterWriter
2012-10-02 18:20:55,945 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1271): NO General Bloom and NO DeleteFamily was added to HFile (/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/13883334-71f4-4de2-9fd1-10cae4ccd87e/testBasicHalfMapFile/regionname/familyname/c30e08a4e3ed48bbbe1ed255d7da0c6e) 
2012-10-02 18:20:55,950 DEBUG [pool-1-thread-1] regionserver.StoreFile(261): Store file /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/13883334-71f4-4de2-9fd1-10cae4ccd87e/testBasicHalfMapFile/1/familyname/c30e08a4e3ed48bbbe1ed255d7da0c6e.regionname is a reference
2012-10-02 18:20:55,951 DEBUG [pool-1-thread-1] regionserver.StoreFile(261): Store file /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/13883334-71f4-4de2-9fd1-10cae4ccd87e/testBasicHalfMapFile/2/familyname/c30e08a4e3ed48bbbe1ed255d7da0c6e.regionname is a reference
2012-10-02 18:20:55,952 INFO  [pool-1-thread-1] regionserver.TestStoreFile(238): Midkey: mi/testBasicHalfMapFile:testBasicHalfMapFile/1349202055943/Put/vlen=0/ts=0
2012-10-02 18:20:55,952 INFO  [pool-1-thread-1] regionserver.TestStoreFile(259): First in top: mitestBasicHalfMapFiletestBasicHalfMapFile:"??
2012-10-02 18:20:55,953 INFO  [pool-1-thread-1] regionserver.TestStoreFile(262): Last in top: zztestBasicHalfMapFiletestBasicHalfMapFile:"??
2012-10-02 18:20:55,953 INFO  [pool-1-thread-1] regionserver.TestStoreFile(272): First in bottom: aatestBasicHalfMapFiletestBasicHalfMapFile:"??
2012-10-02 18:20:55,954 INFO  [pool-1-thread-1] regionserver.TestStoreFile(278): Last in bottom: mhtestBasicHalfMapFiletestBasicHalfMapFile:"??
2012-10-02 18:20:55,956 DEBUG [pool-1-thread-1] regionserver.StoreFile(261): Store file /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/13883334-71f4-4de2-9fd1-10cae4ccd87e/testBasicHalfMapFile/1/familyname/c30e08a4e3ed48bbbe1ed255d7da0c6e.regionname is a reference
2012-10-02 18:20:55,957 DEBUG [pool-1-thread-1] regionserver.StoreFile(261): Store file /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/13883334-71f4-4de2-9fd1-10cae4ccd87e/testBasicHalfMapFile/2/familyname/c30e08a4e3ed48bbbe1ed255d7da0c6e.regionname is a reference
2012-10-02 18:20:55,958 INFO  [pool-1-thread-1] regionserver.TestStoreFile(315): First top when key < bottom: aa/testBasicHalfMapFile:testBasicHalfMapFile/1349202055943/Put/vlen=0/ts=0
2012-10-02 18:20:55,959 INFO  [pool-1-thread-1] regionserver.TestStoreFile(323): Last top when key < bottom: zz/testBasicHalfMapFile:testBasicHalfMapFile/1349202055943/Put/vlen=0/ts=0
2012-10-02 18:20:55,961 DEBUG [pool-1-thread-1] regionserver.StoreFile(261): Store file /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/13883334-71f4-4de2-9fd1-10cae4ccd87e/testBasicHalfMapFile/1/familyname/c30e08a4e3ed48bbbe1ed255d7da0c6e.regionname is a reference
2012-10-02 18:20:55,962 DEBUG [pool-1-thread-1] regionserver.StoreFile(261): Store file /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/13883334-71f4-4de2-9fd1-10cae4ccd87e/testBasicHalfMapFile/2/familyname/c30e08a4e3ed48bbbe1ed255d7da0c6e.regionname is a reference
2012-10-02 18:20:55,963 INFO  [pool-1-thread-1] regionserver.TestStoreFile(350): First bottom when key > top: aa/testBasicHalfMapFile:testBasicHalfMapFile/1349202055943/Put/vlen=0/ts=0
2012-10-02 18:20:55,964 INFO  [pool-1-thread-1] regionserver.TestStoreFile(358): Last bottom when key > top: zz/testBasicHalfMapFile:testBasicHalfMapFile/1349202055943/Put/vlen=0/ts=0
2012-10-02 18:20:56,000 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=bt.Data.fsReadnumops, delta=70
2012-10-02 18:20:56,001 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=bt.Data.fsRead_total, delta=1225058
2012-10-02 18:20:56,001 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=bt.Data.fsBlockReadCnt, delta=70
2012-10-02 18:20:56,001 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=bt.Data.fsBlockReadCacheMissCnt, delta=70
2012-10-02 18:20:56,001 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=fsReadnumops, delta=70
2012-10-02 18:20:56,001 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=fsRead_total, delta=1225058
2012-10-02 18:20:56,001 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=fsBlockReadCnt, delta=70
2012-10-02 18:20:56,001 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=fsBlockReadCacheMissCnt, delta=70
2012-10-02 18:20:56,005 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 70 units of cf.familyname.bt.Data.fsReadnumops towards bt.Data.fsReadnumops
2012-10-02 18:20:56,005 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 1225058 units of cf.familyname.bt.Data.fsRead_total towards bt.Data.fsRead_total
2012-10-02 18:20:56,005 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 70 units of cf.familyname.bt.Data.fsBlockReadCnt towards bt.Data.fsBlockReadCnt
2012-10-02 18:20:56,005 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 70 units of cf.familyname.bt.Data.fsBlockReadCacheMissCnt towards bt.Data.fsBlockReadCacheMissCnt
2012-10-02 18:20:56,006 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 70 units of cf.familyname.fsReadnumops towards fsReadnumops
2012-10-02 18:20:56,006 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 1225058 units of cf.familyname.fsRead_total towards fsRead_total
2012-10-02 18:20:56,006 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 70 units of cf.familyname.fsBlockReadCnt towards fsBlockReadCnt
2012-10-02 18:20:56,006 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 70 units of cf.familyname.fsBlockReadCacheMissCnt towards fsBlockReadCacheMissCnt
2012-10-02 18:20:56,023 INFO  [pool-1-thread-1] hbase.ResourceChecker(157): after: regionserver.TestStoreFile#testBasicHalfMapFile Thread=59 (was 59), OpenFileDescriptor=116 (was 106) - OpenFileDescriptor LEAK? -, MaxFileDescriptor=1024 (was 1024), ConnectionCount=0 (was 0)
2012-10-02 18:20:56,024 INFO  [pool-1-thread-1] hbase.ResourceChecker(139): before: regionserver.TestStoreFile#testReference Thread=59, OpenFileDescriptor=116, MaxFileDescriptor=1024, ConnectionCount=0
2012-10-02 18:20:56,030 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.log.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/e54aa664-f6aa-4092-a7b4-2aa714691642
2012-10-02 18:20:56,036 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.log.dir property value differs in configuration and system: Configuration=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/../logs while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir Erasing configuration value by system value.
2012-10-02 18:20:56,036 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.tmp.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/e54aa664-f6aa-4092-a7b4-2aa714691642
2012-10-02 18:20:56,036 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.tmp.dir property value differs in configuration and system: Configuration=/tmp/hadoop-hudson while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir Erasing configuration value by system value.
2012-10-02 18:20:56,036 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("mapred.working.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/mapred-working-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/e54aa664-f6aa-4092-a7b4-2aa714691642
2012-10-02 18:20:56,045 DEBUG [pool-1-thread-1] util.FSUtils(167): Creating file=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/e54aa664-f6aa-4092-a7b4-2aa714691642/testReference/regionname/familyname/1234567890/4c4dcd2118f9463f92bab4e4e96fea2c with permission=rwxrwxrwx
2012-10-02 18:20:56,045 DEBUG [pool-1-thread-1] hfile.HFileWriterV2(142): Initialized with CacheConfig:enabled [cacheDataOnRead=true] [cacheDataOnWrite=false] [cacheIndexesOnWrite=false] [cacheBloomsOnWrite=false] [cacheEvictOnClose=false] [cacheCompressed=false]
2012-10-02 18:20:56,045 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1051): Delete Family Bloom filter type for /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/e54aa664-f6aa-4092-a7b4-2aa714691642/testReference/regionname/familyname/1234567890/4c4dcd2118f9463f92bab4e4e96fea2c: CompoundBloomFilterWriter
2012-10-02 18:20:56,047 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1271): NO General Bloom and NO DeleteFamily was added to HFile (/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/e54aa664-f6aa-4092-a7b4-2aa714691642/testReference/regionname/familyname/1234567890/4c4dcd2118f9463f92bab4e4e96fea2c) 
2012-10-02 18:20:56,049 DEBUG [pool-1-thread-1] regionserver.StoreFile(261): Store file /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/e54aa664-f6aa-4092-a7b4-2aa714691642/testReference/regionname/familyname/1234567890/4c4dcd2118f9463f92bab4e4e96fea2c.familyname is a reference
2012-10-02 18:20:56,086 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=bt.Data.fsReadnumops, delta=4
2012-10-02 18:20:56,086 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=bt.Data.fsRead_total, delta=128072
2012-10-02 18:20:56,086 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=bt.Data.fsBlockReadCnt, delta=4
2012-10-02 18:20:56,086 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=bt.Data.fsBlockReadCacheMissCnt, delta=4
2012-10-02 18:20:56,087 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=fsReadnumops, delta=4
2012-10-02 18:20:56,087 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=fsRead_total, delta=128072
2012-10-02 18:20:56,087 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=fsBlockReadCnt, delta=4
2012-10-02 18:20:56,087 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(844): Metric=fsBlockReadCacheMissCnt, delta=4
2012-10-02 18:20:56,092 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 4 units of cf.1234567890.bt.Data.fsReadnumops towards bt.Data.fsReadnumops
2012-10-02 18:20:56,092 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 128072 units of cf.1234567890.bt.Data.fsRead_total towards bt.Data.fsRead_total
2012-10-02 18:20:56,092 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 4 units of cf.1234567890.bt.Data.fsBlockReadCnt towards bt.Data.fsBlockReadCnt
2012-10-02 18:20:56,092 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 4 units of cf.1234567890.bt.Data.fsBlockReadCacheMissCnt towards bt.Data.fsBlockReadCacheMissCnt
2012-10-02 18:20:56,092 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 4 units of cf.1234567890.fsReadnumops towards fsReadnumops
2012-10-02 18:20:56,092 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 128072 units of cf.1234567890.fsRead_total towards fsRead_total
2012-10-02 18:20:56,092 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 4 units of cf.1234567890.fsBlockReadCnt towards fsBlockReadCnt
2012-10-02 18:20:56,092 DEBUG [pool-1-thread-1] metrics.SchemaMetrics(837): Counting 4 units of cf.1234567890.fsBlockReadCacheMissCnt towards fsBlockReadCacheMissCnt
2012-10-02 18:20:56,109 INFO  [pool-1-thread-1] hbase.ResourceChecker(157): after: regionserver.TestStoreFile#testReference Thread=59 (was 59), OpenFileDescriptor=120 (was 116) - OpenFileDescriptor LEAK? -, MaxFileDescriptor=1024 (was 1024), ConnectionCount=0 (was 0)
2012-10-02 18:20:56,110 INFO  [pool-1-thread-1] hbase.ResourceChecker(139): before: regionserver.TestStoreFile#testHFileLink Thread=59, OpenFileDescriptor=120, MaxFileDescriptor=1024, ConnectionCount=0
2012-10-02 18:20:56,116 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.log.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/b13b7471-63b8-4953-9a1d-14f3be113ce7
2012-10-02 18:20:56,122 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.log.dir property value differs in configuration and system: Configuration=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/../logs while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir Erasing configuration value by system value.
2012-10-02 18:20:56,122 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.tmp.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/b13b7471-63b8-4953-9a1d-14f3be113ce7
2012-10-02 18:20:56,122 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.tmp.dir property value differs in configuration and system: Configuration=/tmp/hadoop-hudson while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir Erasing configuration value by system value.
2012-10-02 18:20:56,122 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("mapred.working.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/mapred-working-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/b13b7471-63b8-4953-9a1d-14f3be113ce7
2012-10-02 18:20:56,160 DEBUG [pool-1-thread-1] util.FSUtils(167): Creating file=file:/tmp/hbase-hudson/hbase/table-link/fd938f29df8ebe31ad5d39bd04f595ba/cf/e2b17ba0eaaa4f09b735fbbd99907afa with permission=rwxrwxrwx
2012-10-02 18:20:56,161 DEBUG [pool-1-thread-1] hfile.HFileWriterV2(142): Initialized with CacheConfig:enabled [cacheDataOnRead=true] [cacheDataOnWrite=false] [cacheIndexesOnWrite=false] [cacheBloomsOnWrite=false] [cacheEvictOnClose=false] [cacheCompressed=false]
2012-10-02 18:20:56,161 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1051): Delete Family Bloom filter type for file:/tmp/hbase-hudson/hbase/table-link/fd938f29df8ebe31ad5d39bd04f595ba/cf/e2b17ba0eaaa4f09b735fbbd99907afa: CompoundBloomFilterWriter
2012-10-02 18:20:56,162 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1271): NO General Bloom and NO DeleteFamily was added to HFile (file:/tmp/hbase-hudson/hbase/table-link/fd938f29df8ebe31ad5d39bd04f595ba/cf/e2b17ba0eaaa4f09b735fbbd99907afa) 
2012-10-02 18:20:56,162 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1271): NO General Bloom and NO DeleteFamily was added to HFile (file:/tmp/hbase-hudson/hbase/table-link/fd938f29df8ebe31ad5d39bd04f595ba/cf/e2b17ba0eaaa4f09b735fbbd99907afa) 
2012-10-02 18:20:56,185 DEBUG [pool-1-thread-1] regionserver.StoreFile(257): Store file file:/tmp/hbase-hudson/hbase/test-region/cf/e2b17ba0eaaa4f09b735fbbd99907afa-fd938f29df8ebe31ad5d39bd04f595ba-table-link is a link
2012-10-02 18:20:56,210 INFO  [pool-1-thread-1] hbase.ResourceChecker(157): after: regionserver.TestStoreFile#testHFileLink Thread=59 (was 59), OpenFileDescriptor=122 (was 120) - OpenFileDescriptor LEAK? -, MaxFileDescriptor=1024 (was 1024), ConnectionCount=0 (was 0)
2012-10-02 18:20:56,211 INFO  [pool-1-thread-1] hbase.ResourceChecker(139): before: regionserver.TestStoreFile#testBloomFilter Thread=59, OpenFileDescriptor=122, MaxFileDescriptor=1024, ConnectionCount=0
2012-10-02 18:20:56,217 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.log.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ef09e562-94a7-4e78-bf80-06f476037417
2012-10-02 18:20:56,223 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.log.dir property value differs in configuration and system: Configuration=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/../logs while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir Erasing configuration value by system value.
2012-10-02 18:20:56,223 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.tmp.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ef09e562-94a7-4e78-bf80-06f476037417
2012-10-02 18:20:56,223 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.tmp.dir property value differs in configuration and system: Configuration=/tmp/hadoop-hudson while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir Erasing configuration value by system value.
2012-10-02 18:20:56,223 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("mapred.working.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/mapred-working-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ef09e562-94a7-4e78-bf80-06f476037417
2012-10-02 18:20:56,231 DEBUG [pool-1-thread-1] util.FSUtils(167): Creating file=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testBloomFilter with permission=rwxrwxrwx
2012-10-02 18:20:56,232 DEBUG [pool-1-thread-1] hfile.HFileWriterV2(142): Initialized with CacheConfig:enabled [cacheDataOnRead=true] [cacheDataOnWrite=false] [cacheIndexesOnWrite=false] [cacheBloomsOnWrite=false] [cacheEvictOnClose=false] [cacheCompressed=false]
2012-10-02 18:20:56,232 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1034): Bloom filter type for /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testBloomFilter: ROW, CompoundBloomFilterWriter
2012-10-02 18:20:56,232 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1051): Delete Family Bloom filter type for /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testBloomFilter: CompoundBloomFilterWriter
2012-10-02 18:20:56,243 DEBUG [pool-1-thread-1] util.CompoundBloomFilterWriter(139): Compacted Bloom chunk #0 from [109306 max keys, 131072 bytes] to [1707 max keys, 2048 bytes]
2012-10-02 18:20:56,243 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1271): General Bloom and NO DeleteFamily was added to HFile (/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testBloomFilter) 
2012-10-02 18:20:56,244 INFO  [pool-1-thread-1] regionserver.StoreFile$Reader(1639): Loaded ROW (CompoundBloomFilter) metadata for testBloomFilter
2012-10-02 18:20:56,310 INFO  [pool-1-thread-1] hbase.ResourceChecker(157): after: regionserver.TestStoreFile#testBloomFilter Thread=59 (was 59), OpenFileDescriptor=122 (was 122), MaxFileDescriptor=1024 (was 1024), ConnectionCount=0 (was 0)
2012-10-02 18:20:56,311 INFO  [pool-1-thread-1] hbase.ResourceChecker(139): before: regionserver.TestStoreFile#testDeleteFamilyBloomFilter Thread=59, OpenFileDescriptor=122, MaxFileDescriptor=1024, ConnectionCount=0
2012-10-02 18:20:56,317 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.log.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/40680d47-0d5f-4a49-b081-1a1d809e7735
2012-10-02 18:20:56,323 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.log.dir property value differs in configuration and system: Configuration=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/../logs while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir Erasing configuration value by system value.
2012-10-02 18:20:56,323 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.tmp.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/40680d47-0d5f-4a49-b081-1a1d809e7735
2012-10-02 18:20:56,323 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.tmp.dir property value differs in configuration and system: Configuration=/tmp/hadoop-hudson while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir Erasing configuration value by system value.
2012-10-02 18:20:56,323 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("mapred.working.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/mapred-working-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/40680d47-0d5f-4a49-b081-1a1d809e7735
2012-10-02 18:20:56,331 DEBUG [pool-1-thread-1] util.FSUtils(167): Creating file=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testDeleteFamilyBloomFilter with permission=rwxrwxrwx
2012-10-02 18:20:56,332 DEBUG [pool-1-thread-1] hfile.HFileWriterV2(142): Initialized with CacheConfig:enabled [cacheDataOnRead=true] [cacheDataOnWrite=false] [cacheIndexesOnWrite=false] [cacheBloomsOnWrite=false] [cacheEvictOnClose=false] [cacheCompressed=false]
2012-10-02 18:20:56,332 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1051): Delete Family Bloom filter type for /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testDeleteFamilyBloomFilter: CompoundBloomFilterWriter
2012-10-02 18:20:56,342 DEBUG [pool-1-thread-1] util.CompoundBloomFilterWriter(139): Compacted Bloom chunk #0 from [109306 max keys, 131072 bytes] to [1707 max keys, 2048 bytes]
2012-10-02 18:20:56,342 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1271): NO General Bloom and DeleteFamily was added to HFile (/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testDeleteFamilyBloomFilter) 
2012-10-02 18:20:56,343 INFO  [pool-1-thread-1] regionserver.StoreFile$Reader(1652): Loaded Delete Family Bloom (CompoundBloomFilter) metadata for testDeleteFamilyBloomFilter
2012-10-02 18:20:56,395 INFO  [pool-1-thread-1] hbase.ResourceChecker(157): after: regionserver.TestStoreFile#testDeleteFamilyBloomFilter Thread=59 (was 59), OpenFileDescriptor=122 (was 122), MaxFileDescriptor=1024 (was 1024), ConnectionCount=0 (was 0)
2012-10-02 18:20:56,396 INFO  [pool-1-thread-1] hbase.ResourceChecker(139): before: regionserver.TestStoreFile#testBloomTypes Thread=59, OpenFileDescriptor=122, MaxFileDescriptor=1024, ConnectionCount=0
2012-10-02 18:20:56,402 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.log.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/3541c918-926c-4e50-a4d8-9723a5baaaaa
2012-10-02 18:20:56,408 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.log.dir property value differs in configuration and system: Configuration=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/../logs while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir Erasing configuration value by system value.
2012-10-02 18:20:56,408 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.tmp.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/3541c918-926c-4e50-a4d8-9723a5baaaaa
2012-10-02 18:20:56,408 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.tmp.dir property value differs in configuration and system: Configuration=/tmp/hadoop-hudson while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir Erasing configuration value by system value.
2012-10-02 18:20:56,408 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("mapred.working.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/mapred-working-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/3541c918-926c-4e50-a4d8-9723a5baaaaa
2012-10-02 18:20:56,417 DEBUG [pool-1-thread-1] util.FSUtils(167): Creating file=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testBloomTypes0 with permission=rwxrwxrwx
2012-10-02 18:20:56,417 DEBUG [pool-1-thread-1] hfile.HFileWriterV2(142): Initialized with CacheConfig:enabled [cacheDataOnRead=true] [cacheDataOnWrite=false] [cacheIndexesOnWrite=false] [cacheBloomsOnWrite=false] [cacheEvictOnClose=false] [cacheCompressed=false]
2012-10-02 18:20:56,417 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1034): Bloom filter type for /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testBloomTypes0: ROWCOL, CompoundBloomFilterWriter
2012-10-02 18:20:56,427 DEBUG [pool-1-thread-1] util.CompoundBloomFilterWriter(139): Compacted Bloom chunk #0 from [95069 max keys, 131072 bytes] to [742 max keys, 1024 bytes]
2012-10-02 18:20:56,428 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1271): General Bloom and NO DeleteFamily was added to HFile (/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testBloomTypes0) 
2012-10-02 18:20:56,428 INFO  [pool-1-thread-1] regionserver.StoreFile$Reader(1639): Loaded ROWCOL (CompoundBloomFilter) metadata for testBloomTypes0
ROWCOL
  False negatives: 0
  False positives: 0
2012-10-02 18:20:56,496 DEBUG [pool-1-thread-1] util.FSUtils(167): Creating file=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testBloomTypes1 with permission=rwxrwxrwx
2012-10-02 18:20:56,497 DEBUG [pool-1-thread-1] hfile.HFileWriterV2(142): Initialized with CacheConfig:enabled [cacheDataOnRead=true] [cacheDataOnWrite=false] [cacheIndexesOnWrite=false] [cacheBloomsOnWrite=false] [cacheEvictOnClose=false] [cacheCompressed=false]
2012-10-02 18:20:56,497 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1034): Bloom filter type for /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testBloomTypes1: ROW, CompoundBloomFilterWriter
2012-10-02 18:20:56,497 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1051): Delete Family Bloom filter type for /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testBloomTypes1: CompoundBloomFilterWriter
2012-10-02 18:20:56,503 DEBUG [pool-1-thread-1] util.CompoundBloomFilterWriter(139): Compacted Bloom chunk #0 from [109306 max keys, 131072 bytes] to [53 max keys, 64 bytes]
2012-10-02 18:20:56,503 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1271): General Bloom and NO DeleteFamily was added to HFile (/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/ac27f45a-27c4-4de9-85e5-df2cc2a1ee72/TestStoreFile/testBloomTypes1) 
2012-10-02 18:20:56,504 INFO  [pool-1-thread-1] regionserver.StoreFile$Reader(1639): Loaded ROW (CompoundBloomFilter) metadata for testBloomTypes1
ROW
  False negatives: 0
  False positives: 20
2012-10-02 18:20:56,567 INFO  [pool-1-thread-1] hbase.ResourceChecker(157): after: regionserver.TestStoreFile#testBloomTypes Thread=59 (was 59), OpenFileDescriptor=122 (was 122), MaxFileDescriptor=1024 (was 1024), ConnectionCount=0 (was 0)

Standard Error

2012-10-02 18:20:56,110 INFO  [pool-1-thread-1] hbase.ResourceChecker(139): before: regionserver.TestStoreFile#testHFileLink Thread=59, OpenFileDescriptor=120, MaxFileDescriptor=1024, ConnectionCount=0
2012-10-02 18:20:56,116 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.log.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/b13b7471-63b8-4953-9a1d-14f3be113ce7
2012-10-02 18:20:56,122 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.log.dir property value differs in configuration and system: Configuration=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/../logs while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-log-dir Erasing configuration value by system value.
2012-10-02 18:20:56,122 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("hadoop.tmp.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/b13b7471-63b8-4953-9a1d-14f3be113ce7
2012-10-02 18:20:56,122 WARN  [pool-1-thread-1] hbase.HBaseTestingUtility(375): hadoop.tmp.dir property value differs in configuration and system: Configuration=/tmp/hadoop-hudson while System=/home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/hadoop-tmp-dir Erasing configuration value by system value.
2012-10-02 18:20:56,122 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(371): System.getProperty("mapred.working.dir") already set to: /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/24085efb-a368-42e7-bafc-f194032ec1f6/mapred-working-dir so I do NOT create it in /home/hudson/hudson-slave/workspace/HBase-TRUNK/trunk/hbase-server/target/test-data/b13b7471-63b8-4953-9a1d-14f3be113ce7
2012-10-02 18:20:56,160 DEBUG [pool-1-thread-1] util.FSUtils(167): Creating file=file:/tmp/hbase-hudson/hbase/table-link/fd938f29df8ebe31ad5d39bd04f595ba/cf/e2b17ba0eaaa4f09b735fbbd99907afa with permission=rwxrwxrwx
2012-10-02 18:20:56,161 DEBUG [pool-1-thread-1] hfile.HFileWriterV2(142): Initialized with CacheConfig:enabled [cacheDataOnRead=true] [cacheDataOnWrite=false] [cacheIndexesOnWrite=false] [cacheBloomsOnWrite=false] [cacheEvictOnClose=false] [cacheCompressed=false]
2012-10-02 18:20:56,161 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1051): Delete Family Bloom filter type for file:/tmp/hbase-hudson/hbase/table-link/fd938f29df8ebe31ad5d39bd04f595ba/cf/e2b17ba0eaaa4f09b735fbbd99907afa: CompoundBloomFilterWriter
2012-10-02 18:20:56,162 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1271): NO General Bloom and NO DeleteFamily was added to HFile (file:/tmp/hbase-hudson/hbase/table-link/fd938f29df8ebe31ad5d39bd04f595ba/cf/e2b17ba0eaaa4f09b735fbbd99907afa) 
2012-10-02 18:20:56,162 INFO  [pool-1-thread-1] regionserver.StoreFile$Writer(1271): NO General Bloom and NO DeleteFamily was added to HFile (file:/tmp/hbase-hudson/hbase/table-link/fd938f29df8ebe31ad5d39bd04f595ba/cf/e2b17ba0eaaa4f09b735fbbd99907afa) 
2012-10-02 18:20:56,185 DEBUG [pool-1-thread-1] regionserver.StoreFile(257): Store file file:/tmp/hbase-hudson/hbase/test-region/cf/e2b17ba0eaaa4f09b735fbbd99907afa-fd938f29df8ebe31ad5d39bd04f595ba-table-link is a link
2012-10-02 18:20:56,210 INFO  [pool-1-thread-1] hbase.ResourceChecker(157): after: regionserver.TestStoreFile#testHFileLink Thread=59 (was 59), OpenFileDescriptor=122 (was 120) - OpenFileDescriptor LEAK? -, MaxFileDescriptor=1024 (was 1024), ConnectionCount=0 (was 0)
{code}
Here is a more recent failure:
https://builds.apache.org/job/HBase-TRUNK/3410/testReport/org.apache.hadoop.hbase.regionserver/TestStoreFile/testHFileLink/
                
> TestStoreFile sometimes fails with 'Column family prefix used twice'
> --------------------------------------------------------------------
>
>                 Key: HBASE-6928
>                 URL: https://issues.apache.org/jira/browse/HBASE-6928
>             Project: HBase
>          Issue Type: Bug
>            Reporter: Ted Yu
>
> In build #3406, I saw:
> {code}
> java.lang.AssertionError: Column family prefix used twice: cf.cf.bt.Data.fsReadnumops
> 	at org.apache.hadoop.hbase.regionserver.metrics.SchemaMetrics.validateMetricChanges(SchemaMetrics.java:822)
> 	at org.apache.hadoop.hbase.regionserver.TestStoreFile.tearDown(TestStoreFile.java:89)
> {code}

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

Mime
View raw message