You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@hbase.apache.org by "Ted Yu (JIRA)" <ji...@apache.org> on 2012/10/03 01:51:08 UTC

[jira] [Created] (HBASE-6928) TestStoreFile sometimes fails with 'Column family prefix used twice'

Ted Yu created HBASE-6928:
-----------------------------

             Summary: 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

[jira] [Updated] (HBASE-6928) TestStoreFile sometimes fails with 'Column family prefix used twice'

Posted by "stack (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/HBASE-6928?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

stack updated HBASE-6928:
-------------------------

    Attachment: 6928_attempted_fix.txt

I think issue is a clash between random column family name chosen by testHFileLink and the substitute name the backing SchemaMetrics uses if no cf supplied (can happen in tests).

Going to commit to see if this fixes issue.

I can't reproduce locally for whatever reason though I've run it a bunch.
                
> 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
>         Attachments: 6928_attempted_fix.txt, 6928-debug.txt
>
>
> 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

[jira] [Commented] (HBASE-6928) TestStoreFile sometimes fails with 'Column family prefix used twice'

Posted by "Hudson (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/HBASE-6928?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13468354#comment-13468354 ] 

Hudson commented on HBASE-6928:
-------------------------------

Integrated in HBase-TRUNK #3411 (See [https://builds.apache.org/job/HBase-TRUNK/3411/])
    HBASE-6928 TestStoreFile sometimes fails with 'Column family prefix used twice' (Revision 1393284)

     Result = FAILURE
stack : 
Files : 
* /hbase/trunk/hbase-server/src/test/java/org/apache/hadoop/hbase/regionserver/TestStoreFile.java

                
> 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
>         Attachments: 6928-debug.txt
>
>
> 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

[jira] [Commented] (HBASE-6928) TestStoreFile sometimes fails with 'Column family prefix used twice'

Posted by "Hudson (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/HBASE-6928?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13469190#comment-13469190 ] 

Hudson commented on HBASE-6928:
-------------------------------

Integrated in HBase-TRUNK #3421 (See [https://builds.apache.org/job/HBase-TRUNK/3421/])
    HBASE-6928 TestStoreFile sometimes fails with 'Column family prefix used twice' -- ATTEMPTED FIX (Revision 1393923)

     Result = FAILURE
stack : 
Files : 
* /hbase/trunk/hbase-server/src/test/java/org/apache/hadoop/hbase/regionserver/TestStoreFile.java

                
> 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
>         Attachments: 6928_attempted_fix.txt, 6928-debug.txt
>
>
> 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

[jira] [Commented] (HBASE-6928) TestStoreFile sometimes fails with 'Column family prefix used twice'

Posted by "Hudson (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/HBASE-6928?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13468497#comment-13468497 ] 

Hudson commented on HBASE-6928:
-------------------------------

Integrated in HBase-TRUNK-on-Hadoop-2.0.0 #205 (See [https://builds.apache.org/job/HBase-TRUNK-on-Hadoop-2.0.0/205/])
    HBASE-6928 TestStoreFile sometimes fails with 'Column family prefix used twice' (Revision 1393284)

     Result = FAILURE
stack : 
Files : 
* /hbase/trunk/hbase-server/src/test/java/org/apache/hadoop/hbase/regionserver/TestStoreFile.java

                
> 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
>         Attachments: 6928-debug.txt
>
>
> 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

[jira] [Updated] (HBASE-6928) TestStoreFile sometimes fails with 'Column family prefix used twice'

Posted by "stack (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/HBASE-6928?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

stack updated HBASE-6928:
-------------------------

    Attachment: 6928-debug.txt

Added some logging so can at least figure which of the tests failing.
                
> 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
>         Attachments: 6928-debug.txt
>
>
> 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

[jira] [Commented] (HBASE-6928) TestStoreFile sometimes fails with 'Column family prefix used twice'

Posted by "stack (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/HBASE-6928?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13468322#comment-13468322 ] 

stack commented on HBASE-6928:
------------------------------

Committed the debug.  Lets see if it turns up anything.
                
> 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
>         Attachments: 6928-debug.txt
>
>
> 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

[jira] [Commented] (HBASE-6928) TestStoreFile sometimes fails with 'Column family prefix used twice'

Posted by "stack (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/HBASE-6928?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13469173#comment-13469173 ] 

stack commented on HBASE-6928:
------------------------------

Applied attempted fix.  Lets see if it makes a difference.
                
> 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
>         Attachments: 6928_attempted_fix.txt, 6928-debug.txt
>
>
> 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

[jira] [Commented] (HBASE-6928) TestStoreFile sometimes fails with 'Column family prefix used twice'

Posted by "Hudson (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/HBASE-6928?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13469304#comment-13469304 ] 

Hudson commented on HBASE-6928:
-------------------------------

Integrated in HBase-TRUNK-on-Hadoop-2.0.0 #207 (See [https://builds.apache.org/job/HBase-TRUNK-on-Hadoop-2.0.0/207/])
    HBASE-6928 TestStoreFile sometimes fails with 'Column family prefix used twice' -- ATTEMPTED FIX (Revision 1393923)

     Result = SUCCESS
stack : 
Files : 
* /hbase/trunk/hbase-server/src/test/java/org/apache/hadoop/hbase/regionserver/TestStoreFile.java

                
> 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
>         Attachments: 6928_attempted_fix.txt, 6928-debug.txt
>
>
> 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

[jira] [Commented] (HBASE-6928) TestStoreFile sometimes fails with 'Column family prefix used twice'

Posted by "Ted Yu (JIRA)" <ji...@apache.org>.
    [ 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