You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@hbase.apache.org by bijieshan <bi...@huawei.com> on 2011/09/02 04:41:27 UTC

About why did the unit tests get killed//Re: Build failed in Jenkins: hbase-0.90 #282

About this failure, I've seen it several times. I didn't see the detail logs for this one. But in my env, there's always some similar logs :

2011-09-02 09:33:57,517 INFO  [RS_CLOSE_META-linux1.site,53487,1314927226948-0] regionserver.HRegion(554): Closed .META.,,1.1028785192
2011-09-02 09:33:57,517 DEBUG [RS_CLOSE_META-linux1.site,53487,1314927226948-0] handler.CloseRegionHandler(138): Closed region .META.,,1.1028785192
2011-09-02 09:33:57,564 INFO  [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.Store(494): Renaming flushed file at hdfs://localhost:47319/user/root/-ROOT-/70236052/.tmp/1398417344723896979 to hdfs://localhost:47319/user/root/-ROOT-/70236052/info/3663494863054324738
2011-09-02 09:33:57,582 INFO  [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.Store(504): Added hdfs://localhost:47319/user/root/-ROOT-/70236052/info/3663494863054324738, entries=2, sequenceid=40, memsize=464.0, filesize=504.0
2011-09-02 09:33:57,582 INFO  [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.HRegion(1026): Finished memstore flush of ~464.0 for region -ROOT-,,0.70236052 in 847ms, sequenceid=40, compaction requested=false
2011-09-02 09:33:57,583 DEBUG [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.Store(418): closed info
2011-09-02 09:33:57,583 INFO  [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.HRegion(554): Closed -ROOT-,,0.70236052
2011-09-02 09:33:57,583 DEBUG [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] handler.CloseRegionHandler(138): Closed region -ROOT-,,0.70236052
2011-09-02 09:33:57,700 INFO  [RegionServer:0;linux1.site,53487,1314927226948.leaseChecker] regionserver.Leases(124): RegionServer:0;linux1.site,53487,1314927226948.leaseChecker closing leases
2011-09-02 09:33:57,701 INFO  [RegionServer:0;linux1.site,53487,1314927226948.leaseChecker] regionserver.Leases(131): RegionServer:0;linux1.site,53487,1314927226948.leaseChecker closed leases
2011-09-02 09:33:58,230 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:33:58,460 INFO  [RegionServer:0;linux1.site,53487,1314927226948] regionserver.HRegionServer(709): Waiting on 1 regions to close
2011-09-02 09:33:58,460 DEBUG [RegionServer:0;linux1.site,53487,1314927226948] regionserver.HRegionServer(713): {5a8aaf25ba0a3afd05130cb9ccda5b47=test,ddd,1314927235514.5a8aaf25ba0a3afd05130cb9ccda5b47.}
2011-09-02 09:33:59,230 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:34:00,230 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:34:01,231 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:34:02,231 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:34:03,231 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:34:04,232 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:34:05,232 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
 
I've taken a detailed analysis. I think it happens in the below scenario:

One region is at the end of the opening process. But during the time, the cluster is shutting down. The user regions will be closed, and then .META., -ROOT-.
Step A: Cluster shut down.
Step B: Close user regions.
Step C: Close .META. and -ROOT-.

The new region's opening started before the step A, but finished after step B but before step C. So it will be added into onlineRegions. 
Then the .META. and -ROOT- get closed. But the new region can't be closed anymore. 

It's a race here.

Please correct me if am wrong.

Jieshan

-------------------------------------------
发件人: Apache Jenkins Server [mailto:jenkins@builds.apache.org] 
发送时间: 2011年8月31日 18:23
收件人: dev@hbase.apache.org
主题: Build failed in Jenkins: hbase-0.90 #282

See <https://builds.apache.org/job/hbase-0.90/282/changes>

Changes:

[tedyu] revert HBASE-4269 to see if 'Not a host:port pair' error still exists

------------------------------------------
[...truncated 1088 lines...]
Running org.apache.hadoop.hbase.regionserver.TestColumnSeeking
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 11.961 sec
Running org.apache.hadoop.hbase.client.TestMultipleTimestamps
Tests run: 8, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 73.359 sec
Running org.apache.hadoop.hbase.regionserver.TestMemStoreLAB
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.231 sec
Running org.apache.hadoop.hbase.TestZooKeeper
Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 74.577 sec
Running org.apache.hadoop.hbase.regionserver.wal.TestLogRolling
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 321.949 sec
Running org.apache.hadoop.hbase.io.hfile.TestCachedBlockQueue
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.018 sec
Running org.apache.hadoop.hbase.filter.TestPrefixFilter
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.018 sec
Running org.apache.hadoop.hbase.io.TestImmutableBytesWritable
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.hadoop.hbase.io.TestHeapSize
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.03 sec
Running org.apache.hadoop.hbase.rest.model.TestRowModel
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.037 sec
Running org.apache.hadoop.hbase.io.hfile.TestHFileSeek
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 4.851 sec
Running org.apache.hadoop.hbase.regionserver.TestStore
Tests run: 9, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.15 sec
Running org.apache.hadoop.hbase.zookeeper.TestHQuorumPeer
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.24 sec
Running org.apache.hadoop.hbase.regionserver.TestSplitTransactionOnCluster
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 32.021 sec
Running org.apache.hadoop.hbase.rest.TestScannersWithFilters
Tests run: 10, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 21.521 sec
Running org.apache.hadoop.hbase.io.hfile.TestHFilePerformance
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 5.599 sec
Running org.apache.hadoop.hbase.io.TestHbaseObjectWritable
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.061 sec
Running org.apache.hadoop.hbase.regionserver.handler.TestOpenRegionHandler
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.394 sec
Running org.apache.hadoop.hbase.regionserver.TestResettingCounters
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.241 sec
Running org.apache.hadoop.hbase.regionserver.wal.TestHLogSplit
Tests run: 23, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 192.013 sec
Running org.apache.hadoop.hbase.thrift.TestThriftServer
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 36.35 sec
Running org.apache.hadoop.hbase.regionserver.TestRpcMetrics
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.326 sec
Running org.apache.hadoop.hbase.filter.TestColumnPrefixFilter
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.918 sec
Running org.apache.hadoop.hbase.master.TestZKBasedOpenCloseRegion
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 29.065 sec
Running org.apache.hadoop.hbase.TestCompare
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.hadoop.hbase.regionserver.TestExplicitColumnTracker
Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.384 sec
Running org.apache.hadoop.hbase.util.TestEnvironmentEdgeManager
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.16 sec
Running org.apache.hadoop.hbase.io.TestHalfStoreFileReader
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.214 sec
Running org.apache.hadoop.hbase.util.TestDefaultEnvironmentEdge
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.hadoop.hbase.rest.TestTransform
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 43.369 sec
Running org.apache.hadoop.hbase.util.TestFSUtils
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 18.094 sec
Running org.apache.hadoop.hbase.security.TestUser
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.035 sec
Running org.apache.hadoop.hbase.master.TestMasterTransitions
Tests run: 3, Failures: 0, Errors: 0, Skipped: 3, Time elapsed: 81.51 sec
Running org.apache.hadoop.hbase.regionserver.TestScanWildcardColumnTracker
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.083 sec
Running org.apache.hadoop.hbase.regionserver.TestKeyValueSkipListSet
Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.02 sec
Running org.apache.hadoop.hbase.filter.TestPageFilter
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.hadoop.hbase.io.hfile.TestSeekTo
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.177 sec
Running org.apache.hadoop.hbase.filter.TestColumnPaginationFilter
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.hadoop.hbase.rest.TestStatusResource
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 18.673 sec
Running org.apache.hadoop.hbase.executor.TestExecutorService
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 2.177 sec
Running org.apache.hadoop.hbase.client.TestFromClientSide
Tests run: 42, Failures: 0, Errors: 0, Skipped: 3, Time elapsed: 172.022 sec
Running org.apache.hadoop.hbase.replication.TestReplication
Tests run: 1, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 21.697 sec <<< FAILURE!
Running org.apache.hadoop.hbase.regionserver.TestCompaction
Tests run: 9, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 148.063 sec
Running org.apache.hadoop.hbase.filter.TestSingleColumnValueFilter
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.033 sec
Running org.apache.hadoop.hbase.mapreduce.TestTimeRangeMapRed
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 51.801 sec
Running org.apache.hadoop.hbase.zookeeper.TestZooKeeperMainServerArg
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.025 sec
Running org.apache.hadoop.hbase.mapreduce.TestSimpleTotalOrderPartitioner
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.084 sec
Running org.apache.hadoop.hbase.master.TestClockSkewDetection
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.074 sec
Running org.apache.hadoop.hbase.mapreduce.TestHFileOutputFormat
Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 120.408 sec
Running org.apache.hadoop.hbase.master.TestMasterRestartAfterDisablingTable
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 18.634 sec
Running org.apache.hadoop.hbase.regionserver.TestFSErrorsExposed
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 48.239 sec
Running org.apache.hadoop.hbase.client.replication.TestReplicationAdmin
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 6.998 sec
Running org.apache.hadoop.hbase.regionserver.TestScanDeleteTracker
Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.114 sec
Running org.apache.hadoop.hbase.client.TestMetaScanner
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 16.519 sec
Running org.apache.hadoop.hbase.metrics.TestMetricsMBeanBase
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.033 sec
Running org.apache.hadoop.hbase.TestRegionRebalancing
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 82.071 sec
Running org.apache.hadoop.hbase.filter.TestSingleColumnValueExcludeFilter
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.hadoop.hbase.filter.TestInclusiveStopFilter
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.hadoop.hbase.rest.TestTableResource
Tests run: 8, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 49.068 sec
Running org.apache.hadoop.hbase.mapreduce.TestTableSplit
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.hadoop.hbase.TestHBaseTestingUtility
Tests run: 5, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 32.111 sec <<< FAILURE!
Running org.apache.hadoop.hbase.mapreduce.TestLoadIncrementalHFiles
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 32.447 sec
Running org.apache.hadoop.hbase.rest.TestSchemaResource
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 40.85 sec
Running org.apache.hadoop.hbase.regionserver.wal.TestWALReplay
Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 49.512 sec
Running org.apache.hadoop.hbase.regionserver.TestKeyValueScanFixture
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.057 sec
Running org.apache.hadoop.hbase.rest.model.TestTableListModel
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.125 sec
Running org.apache.hadoop.hbase.rest.model.TestColumnSchemaModel
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.03 sec
Running org.apache.hadoop.hbase.regionserver.TestStoreFile
Tests run: 7, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 38.014 sec
Running org.apache.hadoop.hbase.zookeeper.TestZooKeeperNodeTracker
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.354 sec
Running org.apache.hadoop.hbase.regionserver.wal.TestHLogMethods
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.425 sec
Running org.apache.hadoop.hbase.rest.model.TestScannerModel
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.132 sec
Running org.apache.hadoop.hbase.rest.TestVersionResource
Tests run: 7, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 18.463 sec
Running org.apache.hadoop.hbase.filter.TestFilter
Tests run: 18, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 3.239 sec
Running org.apache.hadoop.hbase.regionserver.TestWideScanner
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 17.808 sec
Running org.apache.hadoop.hbase.regionserver.TestSplitTransaction
Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 3.397 sec
Running org.apache.hadoop.hbase.replication.regionserver.TestReplicationSink
Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 24.442 sec
Running org.apache.hadoop.hbase.regionserver.TestGetClosestAtOrBefore
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 21.936 sec
Running org.apache.hadoop.hbase.regionserver.TestReadWriteConsistencyControl
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 10.03 sec
Running org.apache.hadoop.hbase.util.TestMergeTable
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 54.135 sec
Running org.apache.hadoop.hbase.rest.model.TestVersionModel
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.126 sec
Running org.apache.hadoop.hbase.rest.model.TestCellSetModel
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.133 sec
Running org.apache.hadoop.hbase.rest.client.TestRemoteTable
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 29.251 sec
Running org.apache.hadoop.hbase.rest.model.TestStorageClusterStatusModel
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.133 sec
Running org.apache.hadoop.hbase.avro.TestAvroServer
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 49.848 sec
Running org.apache.hadoop.hbase.TestFullLogReconstruction
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 58.015 sec
Running org.apache.hadoop.hbase.TestSerialization
Tests run: 19, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.067 sec
Running org.apache.hadoop.hbase.regionserver.TestKeyValueHeap
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.093 sec
Running org.apache.hadoop.hbase.regionserver.TestStoreScanner
Tests run: 14, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.032 sec
Running org.apache.hadoop.hbase.TestHMsg
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.021 sec
Running org.apache.hadoop.hbase.io.hfile.TestReseekTo
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.227 sec
Running org.apache.hadoop.hbase.regionserver.TestHRegionInfo
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.018 sec
Running org.apache.hadoop.hbase.util.TestIncrementingEnvironmentEdge
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.hadoop.hbase.util.TestKeying
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.hadoop.hbase.regionserver.TestScanner
Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 62.906 sec
Running org.apache.hadoop.hbase.util.TestHBaseFsck
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 42.867 sec
Running org.apache.hadoop.hbase.master.TestRestartCluster
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 48.994 sec
Running org.apache.hadoop.hbase.client.TestShell
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 249.925 sec
Running org.apache.hadoop.hbase.rest.model.TestTableInfoModel
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.129 sec
Running org.apache.hadoop.hbase.TestInfoServers
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 14.846 sec
Running org.apache.hadoop.hbase.master.TestLogsCleaner
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.156 sec
Running org.apache.hadoop.hbase.regionserver.TestMasterAddressManager
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.331 sec
Running org.apache.hadoop.hbase.catalog.TestCatalogTrackerOnCluster
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 143.307 sec
Running org.apache.hadoop.hbase.regionserver.TestQueryMatcher
Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.102 sec
Running org.apache.hadoop.hbase.zookeeper.TestZKTable
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.293 sec
Running org.apache.hadoop.hbase.client.TestAdmin
Tests run: 16, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 231.902 sec
Running org.apache.hadoop.hbase.regionserver.TestPriorityCompactionQueue
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.075 sec
Running org.apache.hadoop.hbase.util.TestMergeTool
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 19.144 sec
Running org.apache.hadoop.hbase.TestAcidGuarantees
Tests run: 3, Failures: 0, Errors: 0, Skipped: 3, Time elapsed: 0.015 sec
Running org.apache.hadoop.hbase.util.TestBase64
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.017 sec
Running org.apache.hadoop.hbase.regionserver.TestMemStore
Tests run: 21, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 47.72 sec
Running org.apache.hadoop.hbase.rest.TestScannerResource
Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 61.546 sec
Running org.apache.hadoop.hbase.io.hfile.TestLruBlockCache
Tests run: 7, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.056 sec
Running org.apache.hadoop.hbase.master.TestDeadServer
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.018 sec
Running org.apache.hadoop.hbase.rest.TestGzipFilter
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 36.159 sec
Running org.apache.hadoop.hbase.mapreduce.TestTableMapReduce
killed.
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 1:14:34.231s
[INFO] Finished at: Wed Aug 31 10:22:33 UTC 2011
[INFO] Final Memory: 31M/361M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.4.3:test (default-test) on project hbase: Error while executing forked tests.; nested exception is org.apache.maven.surefire.booter.shade.org.codehaus.plexus.util.cli.CommandLineException: Error while executing external command, process killed. Process timeout out after 900 seconds -> [Help 1]
[ERROR] 
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR] 
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoExecutionException
Build step 'Invoke top-level Maven targets' marked build as failure
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
Archiving artifacts
Recording test results


Re: About why did the unit tests get killed//Re: Build failed in Jenkins: hbase-0.90 #282

Posted by bijieshan <bi...@huawei.com>.
Yes, I can find it. This is logs in more detail:

2011-09-02 09:33:56,647 INFO  [main] hbase.HBaseTestingUtility(415): Shutting down minicluster
2011-09-02 09:33:56,647 DEBUG [main] util.JVMClusterUtil(209): Shutting down HBase Cluster
2011-09-02 09:33:56,647 INFO  [main] master.HMaster(986): Cluster shutdown requested
2011-09-02 09:33:56,661 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(252): master:40897-0x13227c52ede0000 Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/shutdown
2011-09-02 09:33:56,662 DEBUG [RegionServer:0;linux1.site,53487,1314927226948-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:53487-0x13227c52ede0002 Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/shutdown
2011-09-02 09:33:56,663 DEBUG [RegionServer:0;linux1.site,53487,1314927226948-EventThread] zookeeper.ZKUtil(233): regionserver:53487-0x13227c52ede0002 Set watcher on existing znode /hbase/shutdown
2011-09-02 09:33:56,663 DEBUG [main-EventThread] zookeeper.ZKUtil(233): master:40897-0x13227c52ede0000 Set watcher on existing znode /hbase/shutdown
2011-09-02 09:33:56,674 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-1] regionserver.HRegion(373): Onlined test,ddd,1314927235514.5a8aaf25ba0a3afd05130cb9ccda5b47.; next sequenceid=1
2011-09-02 09:33:56,674 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-1] zookeeper.ZKAssign(661): regionserver:53487-0x13227c52ede0002 Attempting to transition node 5a8aaf25ba0a3afd05130cb9ccda5b47 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-09-02 09:33:56,675 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-1] zookeeper.ZKUtil(1109): regionserver:53487-0x13227c52ede0002 Retrieved 101 byte(s) of data from znode /hbase/unassigned/5a8aaf25ba0a3afd05130cb9ccda5b47; data=region=test,ddd,1314927235514.5a8aaf25ba0a3afd05130cb9ccda5b47., server=linux1.site,53487,1314927226948, state=RS_ZK_REGION_OPENING
2011-09-02 09:33:56,675 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] regionserver.HRegion(373): Onlined test,eee,1314927235522.eac06e32b099ec2f657e4d2e80ba6123.; next sequenceid=1
2011-09-02 09:33:56,676 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] zookeeper.ZKAssign(661): regionserver:53487-0x13227c52ede0002 Attempting to transition node eac06e32b099ec2f657e4d2e80ba6123 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-09-02 09:33:56,686 DEBUG [RegionServer:0;linux1.site,53487,1314927226948-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:53487-0x13227c52ede0002 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/5a8aaf25ba0a3afd05130cb9ccda5b47
2011-09-02 09:33:56,687 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-1] zookeeper.ZKAssign(712): regionserver:53487-0x13227c52ede0002 Successfully transitioned node 5a8aaf25ba0a3afd05130cb9ccda5b47 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-09-02 09:33:56,687 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(252): master:40897-0x13227c52ede0000 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/5a8aaf25ba0a3afd05130cb9ccda5b47
2011-09-02 09:33:56,687 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] zookeeper.ZKUtil(1109): regionserver:53487-0x13227c52ede0002 Retrieved 101 byte(s) of data from znode /hbase/unassigned/eac06e32b099ec2f657e4d2e80ba6123; data=region=test,eee,1314927235522.eac06e32b099ec2f657e4d2e80ba6123., server=linux1.site,53487,1314927226948, state=RS_ZK_REGION_OPENING
2011-09-02 09:33:56,688 DEBUG [main-EventThread] zookeeper.ZKUtil(1109): master:40897-0x13227c52ede0000 Retrieved 101 byte(s) of data from znode /hbase/unassigned/5a8aaf25ba0a3afd05130cb9ccda5b47 and set watcher; region=test,ddd,1314927235514.5a8aaf25ba0a3afd05130cb9ccda5b47., server=linux1.site,53487,1314927226948, state=RS_ZK_REGION_OPENING
2011-09-02 09:33:56,688 DEBUG [main-EventThread] master.AssignmentManager(475): Handling transition=RS_ZK_REGION_OPENING, server=linux1.site,53487,1314927226948, region=5a8aaf25ba0a3afd05130cb9ccda5b47
2011-09-02 09:33:56,690 INFO  [PostOpenDeployTasks:5a8aaf25ba0a3afd05130cb9ccda5b47] catalog.MetaEditor(165): Updated row test,ddd,1314927235514.5a8aaf25ba0a3afd05130cb9ccda5b47. in region .META.,,1 with server=linux1.site:53487, startcode=1314927226948
2011-09-02 09:33:56,690 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-1] zookeeper.ZKAssign(661): regionserver:53487-0x13227c52ede0002 Attempting to transition node 5a8aaf25ba0a3afd05130cb9ccda5b47 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
2011-09-02 09:33:56,722 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-0] handler.CloseRegionHandler(100): Processing close of test,bbb,1314927235500.093dcd0e98d871c984ea9c9671d8fdeb.
2011-09-02 09:33:56,722 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-0] regionserver.HRegion(515): Closing test,bbb,1314927235500.093dcd0e98d871c984ea9c9671d8fdeb.: disabling compactions & flushes
2011-09-02 09:33:56,722 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-1] handler.CloseRegionHandler(100): Processing close of test,,1314927234195.6747f97a4079a9a7ac49add42a3f5661.
2011-09-02 09:33:56,723 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-0] regionserver.HRegion(543): Updates disabled for region test,bbb,1314927235500.093dcd0e98d871c984ea9c9671d8fdeb.
2011-09-02 09:33:56,724 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-0] regionserver.HRegion(926): Started memstore flush for test,bbb,1314927235500.093dcd0e98d871c984ea9c9671d8fdeb., current region memstore size 208.0
2011-09-02 09:33:56,724 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-0] regionserver.HRegion(964): Finished snapshotting, commencing flushing stores
2011-09-02 09:33:56,723 WARN  [RegionServer:0;linux1.site,53487,1314927226948] regionserver.HRegionServer(2168): Received close for region we are already opening or closing; 5a8aaf25ba0a3afd05130cb9ccda5b47
2011-09-02 09:33:56,723 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-1] regionserver.HRegion(515): Closing test,,1314927234195.6747f97a4079a9a7ac49add42a3f5661.: disabling compactions & flushes
2011-09-02 09:33:56,725 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-1] regionserver.HRegion(543): Updates disabled for region test,,1314927234195.6747f97a4079a9a7ac49add42a3f5661.
2011-09-02 09:33:56,725 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-1] regionserver.Store(418): closed f
2011-09-02 09:33:56,725 INFO  [RS_CLOSE_REGION-linux1.site,53487,1314927226948-1] regionserver.HRegion(554): Closed test,,1314927234195.6747f97a4079a9a7ac49add42a3f5661.
2011-09-02 09:33:56,725 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-1] handler.CloseRegionHandler(138): Closed region test,,1314927234195.6747f97a4079a9a7ac49add42a3f5661.
2011-09-02 09:33:56,725 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-1] handler.CloseRegionHandler(100): Processing close of test,,1314927235489.1423931be2c1acd2811b1261423bc505.
2011-09-02 09:33:56,724 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-2] handler.CloseRegionHandler(100): Processing close of test,ccc,1314927235507.4f7073bc3e99deeab79b309d896bd67d.
2011-09-02 09:33:56,726 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-1] regionserver.HRegion(515): Closing test,,1314927235489.1423931be2c1acd2811b1261423bc505.: disabling compactions & flushes
2011-09-02 09:33:56,727 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-1] regionserver.HRegion(543): Updates disabled for region test,,1314927235489.1423931be2c1acd2811b1261423bc505.
2011-09-02 09:33:56,727 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-1] regionserver.Store(418): closed f
2011-09-02 09:33:56,727 INFO  [RS_CLOSE_REGION-linux1.site,53487,1314927226948-1] regionserver.HRegion(554): Closed test,,1314927235489.1423931be2c1acd2811b1261423bc505.
2011-09-02 09:33:56,727 INFO  [RegionServer:0;linux1.site,53487,1314927226948] regionserver.HRegionServer(750): STOP_REGIONSERVER
2011-09-02 09:33:56,728 INFO  [RegionServer:0;linux1.site,53487,1314927226948] regionserver.HRegionServer(1342): STOPPED: Received STOP_REGIONSERVER
2011-09-02 09:33:56,727 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-2] regionserver.HRegion(515): Closing test,ccc,1314927235507.4f7073bc3e99deeab79b309d896bd67d.: disabling compactions & flushes
2011-09-02 09:33:56,727 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-1] handler.CloseRegionHandler(138): Closed region test,,1314927235489.1423931be2c1acd2811b1261423bc505.
2011-09-02 09:33:56,728 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-2] regionserver.HRegion(543): Updates disabled for region test,ccc,1314927235507.4f7073bc3e99deeab79b309d896bd67d.
2011-09-02 09:33:56,729 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-2] regionserver.Store(418): closed f
2011-09-02 09:33:56,729 INFO  [RS_CLOSE_REGION-linux1.site,53487,1314927226948-2] regionserver.HRegion(554): Closed test,ccc,1314927235507.4f7073bc3e99deeab79b309d896bd67d.
2011-09-02 09:33:56,729 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-2] handler.CloseRegionHandler(138): Closed region test,ccc,1314927235507.4f7073bc3e99deeab79b309d896bd67d.
2011-09-02 09:33:56,732 WARN  [RegionServer:0;linux1.site,53487,1314927226948] regionserver.HRegionServer(2168): Received close for region we are already opening or closing; 093dcd0e98d871c984ea9c9671d8fdeb
2011-09-02 09:33:56,732 INFO  [RegionServer:0;linux1.site,53487,1314927226948.majorCompactionChecker] hbase.Chore(79): RegionServer:0;linux1.site,53487,1314927226948.majorCompactionChecker exiting
2011-09-02 09:33:56,732 INFO  [RegionServer:0;linux1.site,53487,1314927226948.cacheFlusher] regionserver.MemStoreFlusher(266): RegionServer:0;linux1.site,53487,1314927226948.cacheFlusher exiting
2011-09-02 09:33:56,732 INFO  [RegionServer:0;linux1.site,53487,1314927226948.compactor] regionserver.CompactSplitThread(113): RegionServer:0;linux1.site,53487,1314927226948.compactor exiting
2011-09-02 09:33:56,732 WARN  [RegionServer:0;linux1.site,53487,1314927226948] regionserver.HRegionServer(2168): Received close for region we are already opening or closing; 5a8aaf25ba0a3afd05130cb9ccda5b47
2011-09-02 09:33:56,732 INFO  [RegionServer:0;linux1.site,53487,1314927226948.logRoller] regionserver.LogRoller(114): LogRoller exiting.
2011-09-02 09:33:56,733 DEBUG [RS_CLOSE_META-linux1.site,53487,1314927226948-0] handler.CloseRegionHandler(100): Processing close of .META.,,1.1028785192
2011-09-02 09:33:56,734 DEBUG [RS_CLOSE_META-linux1.site,53487,1314927226948-0] regionserver.HRegion(515): Closing .META.,,1.1028785192: disabling compactions & flushes
2011-09-02 09:33:56,734 DEBUG [RegionServer:0;linux1.site,53487,1314927226948.logSyncer] wal.HLog$LogSyncer(980): RegionServer:0;linux1.site,53487,1314927226948.logSyncer interrupted while waiting for sync requests
2011-09-02 09:33:56,734 DEBUG [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] handler.CloseRegionHandler(100): Processing close of -ROOT-,,0.70236052
2011-09-02 09:33:56,734 DEBUG [RS_CLOSE_META-linux1.site,53487,1314927226948-0] regionserver.HRegion(543): Updates disabled for region .META.,,1.1028785192
2011-09-02 09:33:56,734 INFO  [RegionServer:0;linux1.site,53487,1314927226948.logSyncer] wal.HLog$LogSyncer(982): RegionServer:0;linux1.site,53487,1314927226948.logSyncer exiting
2011-09-02 09:33:56,734 DEBUG [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.HRegion(515): Closing -ROOT-,,0.70236052: disabling compactions & flushes
2011-09-02 09:33:56,735 DEBUG [RS_CLOSE_META-linux1.site,53487,1314927226948-0] regionserver.HRegion(926): Started memstore flush for .META.,,1.1028785192, current region memstore size 18.0k
2011-09-02 09:33:56,735 DEBUG [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.HRegion(543): Updates disabled for region -ROOT-,,0.70236052
2011-09-02 09:33:56,735 DEBUG [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.HRegion(926): Started memstore flush for -ROOT-,,0.70236052, current region memstore size 464.0
2011-09-02 09:33:56,755 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(252): master:40897-0x13227c52ede0000 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/eac06e32b099ec2f657e4d2e80ba6123
2011-09-02 09:33:56,755 DEBUG [RegionServer:0;linux1.site,53487,1314927226948-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:53487-0x13227c52ede0002 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/eac06e32b099ec2f657e4d2e80ba6123
2011-09-02 09:33:56,755 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] zookeeper.ZKAssign(712): regionserver:53487-0x13227c52ede0002 Successfully transitioned node eac06e32b099ec2f657e4d2e80ba6123 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-09-02 09:33:56,755 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] regionserver.HRegion(515): Closing test,eee,1314927235522.eac06e32b099ec2f657e4d2e80ba6123.: disabling compactions & flushes
2011-09-02 09:33:56,755 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] regionserver.HRegion(543): Updates disabled for region test,eee,1314927235522.eac06e32b099ec2f657e4d2e80ba6123.
2011-09-02 09:33:56,755 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] regionserver.Store(418): closed f
2011-09-02 09:33:56,756 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] regionserver.HRegion(554): Closed test,eee,1314927235522.eac06e32b099ec2f657e4d2e80ba6123.
2011-09-02 09:33:56,755 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-1] zookeeper.ZKUtil(1109): regionserver:53487-0x13227c52ede0002 Retrieved 101 byte(s) of data from znode /hbase/unassigned/5a8aaf25ba0a3afd05130cb9ccda5b47; data=region=test,ddd,1314927235514.5a8aaf25ba0a3afd05130cb9ccda5b47., server=linux1.site,53487,1314927226948, state=RS_ZK_REGION_OPENING
2011-09-02 09:33:56,756 DEBUG [main-EventThread] zookeeper.ZKUtil(1109): master:40897-0x13227c52ede0000 Retrieved 101 byte(s) of data from znode /hbase/unassigned/eac06e32b099ec2f657e4d2e80ba6123 and set watcher; region=test,eee,1314927235522.eac06e32b099ec2f657e4d2e80ba6123., server=linux1.site,53487,1314927226948, state=RS_ZK_REGION_OPENING
2011-09-02 09:33:56,756 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(74): Processing open of test,ggg,1314927235539.d231bd0ed4359b6f317316f05eaced16.
2011-09-02 09:33:56,756 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(76): Server stopping or stopped, skipping open of test,ggg,1314927235539.d231bd0ed4359b6f317316f05eaced16.
2011-09-02 09:33:56,756 DEBUG [main-EventThread] master.AssignmentManager(475): Handling transition=RS_ZK_REGION_OPENING, server=linux1.site,53487,1314927226948, region=eac06e32b099ec2f657e4d2e80ba6123
2011-09-02 09:33:56,757 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(74): Processing open of test,hhh,1314927235546.c7503560dc0b6f0d77f930da429b96fa.
2011-09-02 09:33:56,757 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(76): Server stopping or stopped, skipping open of test,hhh,1314927235546.c7503560dc0b6f0d77f930da429b96fa.
2011-09-02 09:33:56,757 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(74): Processing open of test,iii,1314927235552.139a8d6d2d753393705c0ea0996a7755.
2011-09-02 09:33:56,757 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(76): Server stopping or stopped, skipping open of test,iii,1314927235552.139a8d6d2d753393705c0ea0996a7755.
2011-09-02 09:33:56,758 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(74): Processing open of test,jjj,1314927235575.0cebcda45dbccf7a6763b8b8bfa2b0a4.
2011-09-02 09:33:56,758 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(76): Server stopping or stopped, skipping open of test,jjj,1314927235575.0cebcda45dbccf7a6763b8b8bfa2b0a4.
2011-09-02 09:33:56,759 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(74): Processing open of test,kkk,1314927235580.862a7e731110ba1b57d50b72582f9e63.
2011-09-02 09:33:56,759 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(76): Server stopping or stopped, skipping open of test,kkk,1314927235580.862a7e731110ba1b57d50b72582f9e63.
2011-09-02 09:33:56,759 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(74): Processing open of test,lll,1314927235585.9fe4988d570294fed7d1008acda440f5.
2011-09-02 09:33:56,759 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(76): Server stopping or stopped, skipping open of test,lll,1314927235585.9fe4988d570294fed7d1008acda440f5.
2011-09-02 09:33:56,760 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(74): Processing open of test,mmm,1314927235589.8fdcb5959d1f852e6f23a6827f15262e.
2011-09-02 09:33:56,760 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-0] regionserver.HRegion(373): Onlined test,fff,1314927235531.3edcd86dd37dda6a229e461057ae233f.; next sequenceid=1
2011-09-02 09:33:56,760 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(76): Server stopping or stopped, skipping open of test,mmm,1314927235589.8fdcb5959d1f852e6f23a6827f15262e.
2011-09-02 09:33:56,760 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-0] zookeeper.ZKAssign(661): regionserver:53487-0x13227c52ede0002 Attempting to transition node 3edcd86dd37dda6a229e461057ae233f from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-09-02 09:33:56,761 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(74): Processing open of test,nnn,1314927235595.97874fd4de264976e003833c9f8bc684.
2011-09-02 09:33:56,761 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(76): Server stopping or stopped, skipping open of test,nnn,1314927235595.97874fd4de264976e003833c9f8bc684.
2011-09-02 09:33:56,761 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(74): Processing open of test,ooo,1314927235602.cf7f9391564954b4822f0bc62568ac3d.
2011-09-02 09:33:56,761 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(76): Server stopping or stopped, skipping open of test,ooo,1314927235602.cf7f9391564954b4822f0bc62568ac3d.
2011-09-02 09:33:56,761 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(74): Processing open of test,ppp,1314927235609.83f0907bf3b0ae38e4b53dd46dfabc30.
2011-09-02 09:33:56,761 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(76): Server stopping or stopped, skipping open of test,ppp,1314927235609.83f0907bf3b0ae38e4b53dd46dfabc30.
2011-09-02 09:33:56,762 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(74): Processing open of test,qqq,1314927235617.e59d24620ba709a43c7b8e012d4bbed9.
2011-09-02 09:33:56,762 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(76): Server stopping or stopped, skipping open of test,qqq,1314927235617.e59d24620ba709a43c7b8e012d4bbed9.
2011-09-02 09:33:56,762 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(74): Processing open of test,rrr,1314927235625.711f44d309fc407d5b5f84a78ad5de8a.
2011-09-02 09:33:56,762 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(76): Server stopping or stopped, skipping open of test,rrr,1314927235625.711f44d309fc407d5b5f84a78ad5de8a.
2011-09-02 09:33:56,762 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(74): Processing open of test,sss,1314927235632.60a1294b2a0aec256ba17a649e94bdc1.
2011-09-02 09:33:56,762 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(76): Server stopping or stopped, skipping open of test,sss,1314927235632.60a1294b2a0aec256ba17a649e94bdc1.
2011-09-02 09:33:56,762 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(74): Processing open of test,ttt,1314927235677.6b4e6658f5a329d63a66792b68b858a5.
2011-09-02 09:33:56,762 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(76): Server stopping or stopped, skipping open of test,ttt,1314927235677.6b4e6658f5a329d63a66792b68b858a5.
2011-09-02 09:33:56,763 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(74): Processing open of test,uuu,1314927235722.947e0b59a9b918ba57e52d3287608d2d.
2011-09-02 09:33:56,763 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(76): Server stopping or stopped, skipping open of test,uuu,1314927235722.947e0b59a9b918ba57e52d3287608d2d.
2011-09-02 09:33:56,763 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(74): Processing open of test,vvv,1314927235769.f1038d808b629fc7196272bc745f2da2.
2011-09-02 09:33:56,763 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(76): Server stopping or stopped, skipping open of test,vvv,1314927235769.f1038d808b629fc7196272bc745f2da2.
2011-09-02 09:33:56,763 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(74): Processing open of test,www,1314927235817.817b21bdc1deff3065272a64e87bb296.
2011-09-02 09:33:56,763 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(76): Server stopping or stopped, skipping open of test,www,1314927235817.817b21bdc1deff3065272a64e87bb296.
2011-09-02 09:33:56,763 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(74): Processing open of test,xxx,1314927235865.075eb983cb8e7922526c1d2c25fdf183.
2011-09-02 09:33:56,763 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(76): Server stopping or stopped, skipping open of test,xxx,1314927235865.075eb983cb8e7922526c1d2c25fdf183.
2011-09-02 09:33:56,764 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(74): Processing open of test,yyy,1314927235913.d3e9da2011e463b6a3a52952895d57e0.
2011-09-02 09:33:56,764 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-2] handler.OpenRegionHandler(76): Server stopping or stopped, skipping open of test,yyy,1314927235913.d3e9da2011e463b6a3a52952895d57e0.
2011-09-02 09:33:56,776 DEBUG [RegionServer:0;linux1.site,53487,1314927226948-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:53487-0x13227c52ede0002 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/5a8aaf25ba0a3afd05130cb9ccda5b47
2011-09-02 09:33:56,776 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(252): master:40897-0x13227c52ede0000 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/5a8aaf25ba0a3afd05130cb9ccda5b47
2011-09-02 09:33:56,777 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-0] zookeeper.ZKUtil(1109): regionserver:53487-0x13227c52ede0002 Retrieved 101 byte(s) of data from znode /hbase/unassigned/3edcd86dd37dda6a229e461057ae233f; data=region=test,fff,1314927235531.3edcd86dd37dda6a229e461057ae233f., server=linux1.site,53487,1314927226948, state=RS_ZK_REGION_OPENING
2011-09-02 09:33:56,777 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-1] zookeeper.ZKAssign(712): regionserver:53487-0x13227c52ede0002 Successfully transitioned node 5a8aaf25ba0a3afd05130cb9ccda5b47 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
2011-09-02 09:33:56,777 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-1] handler.OpenRegionHandler(118): Opened test,ddd,1314927235514.5a8aaf25ba0a3afd05130cb9ccda5b47.
2011-09-02 09:33:56,778 DEBUG [main-EventThread] zookeeper.ZKUtil(1109): master:40897-0x13227c52ede0000 Retrieved 101 byte(s) of data from znode /hbase/unassigned/5a8aaf25ba0a3afd05130cb9ccda5b47 and set watcher; region=test,ddd,1314927235514.5a8aaf25ba0a3afd05130cb9ccda5b47., server=linux1.site,53487,1314927226948, state=RS_ZK_REGION_OPENED
2011-09-02 09:33:56,778 DEBUG [main-EventThread] master.AssignmentManager(475): Handling transition=RS_ZK_REGION_OPENED, server=linux1.site,53487,1314927226948, region=5a8aaf25ba0a3afd05130cb9ccda5b47
2011-09-02 09:33:56,778 DEBUG [MASTER_OPEN_REGION-linux1.site:40897-1] handler.OpenedRegionHandler(84): Handling OPENED event for 5a8aaf25ba0a3afd05130cb9ccda5b47; deleting unassigned node
2011-09-02 09:33:56,778 DEBUG [MASTER_OPEN_REGION-linux1.site:40897-1] zookeeper.ZKAssign(393): master:40897-0x13227c52ede0000 Deleting existing unassigned node for 5a8aaf25ba0a3afd05130cb9ccda5b47 that is in expected state RS_ZK_REGION_OPENED
2011-09-02 09:33:56,794 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(252): master:40897-0x13227c52ede0000 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/3edcd86dd37dda6a229e461057ae233f
2011-09-02 09:33:56,794 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-0] zookeeper.ZKAssign(712): regionserver:53487-0x13227c52ede0002 Successfully transitioned node 3edcd86dd37dda6a229e461057ae233f from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-09-02 09:33:56,795 DEBUG [MASTER_OPEN_REGION-linux1.site:40897-1] zookeeper.ZKUtil(1109): master:40897-0x13227c52ede0000 Retrieved 101 byte(s) of data from znode /hbase/unassigned/5a8aaf25ba0a3afd05130cb9ccda5b47; data=region=test,ddd,1314927235514.5a8aaf25ba0a3afd05130cb9ccda5b47., server=linux1.site,53487,1314927226948, state=RS_ZK_REGION_OPENED
2011-09-02 09:33:56,794 DEBUG [RegionServer:0;linux1.site,53487,1314927226948-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:53487-0x13227c52ede0002 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/3edcd86dd37dda6a229e461057ae233f
2011-09-02 09:33:56,795 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-0] regionserver.HRegion(515): Closing test,fff,1314927235531.3edcd86dd37dda6a229e461057ae233f.: disabling compactions & flushes
2011-09-02 09:33:56,795 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-0] regionserver.HRegion(543): Updates disabled for region test,fff,1314927235531.3edcd86dd37dda6a229e461057ae233f.
2011-09-02 09:33:56,795 DEBUG [RS_OPEN_REGION-linux1.site,53487,1314927226948-0] regionserver.Store(418): closed f
2011-09-02 09:33:56,795 DEBUG [main-EventThread] zookeeper.ZKUtil(1109): master:40897-0x13227c52ede0000 Retrieved 101 byte(s) of data from znode /hbase/unassigned/3edcd86dd37dda6a229e461057ae233f and set watcher; region=test,fff,1314927235531.3edcd86dd37dda6a229e461057ae233f., server=linux1.site,53487,1314927226948, state=RS_ZK_REGION_OPENING
2011-09-02 09:33:56,796 INFO  [RS_OPEN_REGION-linux1.site,53487,1314927226948-0] regionserver.HRegion(554): Closed test,fff,1314927235531.3edcd86dd37dda6a229e461057ae233f.
2011-09-02 09:33:56,796 DEBUG [main-EventThread] master.AssignmentManager(475): Handling transition=RS_ZK_REGION_OPENING, server=linux1.site,53487,1314927226948, region=3edcd86dd37dda6a229e461057ae233f
2011-09-02 09:33:56,813 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(252): master:40897-0x13227c52ede0000 Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/unassigned/5a8aaf25ba0a3afd05130cb9ccda5b47
2011-09-02 09:33:56,813 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(252): master:40897-0x13227c52ede0000 Received ZooKeeper Event, type=NodeChildrenChanged, state=SyncConnected, path=/hbase/unassigned
2011-09-02 09:33:56,813 DEBUG [MASTER_OPEN_REGION-linux1.site:40897-1] zookeeper.ZKAssign(420): master:40897-0x13227c52ede0000 Successfully deleted unassigned node for region 5a8aaf25ba0a3afd05130cb9ccda5b47 in expected state RS_ZK_REGION_OPENED
2011-09-02 09:33:56,815 DEBUG [MASTER_OPEN_REGION-linux1.site:40897-1] handler.OpenedRegionHandler(108): Opened region test,ddd,1314927235514.5a8aaf25ba0a3afd05130cb9ccda5b47. on linux1.site,53487,1314927226948
2011-09-02 09:33:56,980 INFO  [RS_CLOSE_REGION-linux1.site,53487,1314927226948-0] regionserver.Store(494): Renaming flushed file at hdfs://localhost:47319/user/root/test/093dcd0e98d871c984ea9c9671d8fdeb/.tmp/4875255998015919415 to hdfs://localhost:47319/user/root/test/093dcd0e98d871c984ea9c9671d8fdeb/f/6387717706818513918
2011-09-02 09:33:57,000 INFO  [RS_CLOSE_REGION-linux1.site,53487,1314927226948-0] regionserver.Store(504): Added hdfs://localhost:47319/user/root/test/093dcd0e98d871c984ea9c9671d8fdeb/f/6387717706818513918, entries=1, sequenceid=38, memsize=208.0, filesize=385.0
2011-09-02 09:33:57,001 INFO  [RS_CLOSE_REGION-linux1.site,53487,1314927226948-0] regionserver.HRegion(1026): Finished memstore flush of ~208.0 for region test,bbb,1314927235500.093dcd0e98d871c984ea9c9671d8fdeb. in 277ms, sequenceid=38, compaction requested=false
2011-09-02 09:33:57,001 DEBUG [RegionServer:0;linux1.site,53487,1314927226948] wal.HLog(828): closing hlog writer in hdfs://localhost:47319/user/root/.logs/linux1.site,53487,1314927226948
2011-09-02 09:33:57,002 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-0] regionserver.Store(418): closed f
2011-09-02 09:33:57,002 INFO  [RS_CLOSE_REGION-linux1.site,53487,1314927226948-0] regionserver.HRegion(554): Closed test,bbb,1314927235500.093dcd0e98d871c984ea9c9671d8fdeb.
2011-09-02 09:33:57,002 DEBUG [RS_CLOSE_REGION-linux1.site,53487,1314927226948-0] handler.CloseRegionHandler(138): Closed region test,bbb,1314927235500.093dcd0e98d871c984ea9c9671d8fdeb.
2011-09-02 09:33:57,229 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:33:57,230 INFO  [linux1.site:40897-BalancerChore] hbase.Chore(79): linux1.site:40897-BalancerChore exiting
2011-09-02 09:33:57,230 INFO  [linux1.site:40897-CatalogJanitor] hbase.Chore(79): linux1.site:40897-CatalogJanitor exiting
2011-09-02 09:33:57,421 DEBUG [RS_CLOSE_META-linux1.site,53487,1314927226948-0] regionserver.HRegion(964): Finished snapshotting, commencing flushing stores
2011-09-02 09:33:57,435 DEBUG [RegionServer:0;linux1.site,53487,1314927226948] wal.HLog(796): Moved 1 log files to /user/root/.oldlogs
2011-09-02 09:33:57,459 INFO  [RegionServer:0;linux1.site,53487,1314927226948] regionserver.HRegionServer(668): stopping server at: linux1.site,53487,1314927226948
2011-09-02 09:33:57,460 DEBUG [RegionServer:0;linux1.site,53487,1314927226948] catalog.CatalogTracker(146): Stopping catalog tracker org.apache.hadoop.hbase.catalog.CatalogTracker@10439d3b
2011-09-02 09:33:57,460 INFO  [RegionServer:0;linux1.site,53487,1314927226948] regionserver.HRegionServer(709): Waiting on 3 regions to close
2011-09-02 09:33:57,460 DEBUG [RegionServer:0;linux1.site,53487,1314927226948] regionserver.HRegionServer(713): {1028785192=.META.,,1.1028785192, 5a8aaf25ba0a3afd05130cb9ccda5b47=test,ddd,1314927235514.5a8aaf25ba0a3afd05130cb9ccda5b47., 70236052=-ROOT-,,0.70236052}
2011-09-02 09:33:57,499 INFO  [RS_CLOSE_META-linux1.site,53487,1314927226948-0] regionserver.Store(494): Renaming flushed file at hdfs://localhost:47319/user/root/.META./1028785192/.tmp/7638102664000276336 to hdfs://localhost:47319/user/root/.META./1028785192/info/4543915564405360215
2011-09-02 09:33:57,505 INFO  [linux1.site:40897.timeoutMonitor] hbase.Chore(79): linux1.site:40897.timeoutMonitor exiting
2011-09-02 09:33:57,516 INFO  [RS_CLOSE_META-linux1.site,53487,1314927226948-0] regionserver.Store(504): Added hdfs://localhost:47319/user/root/.META./1028785192/info/4543915564405360215, entries=37, sequenceid=39, memsize=18.0k, filesize=12.1k
2011-09-02 09:33:57,516 INFO  [RS_CLOSE_META-linux1.site,53487,1314927226948-0] regionserver.HRegion(1026): Finished memstore flush of ~18.0k for region .META.,,1.1028785192 in 781ms, sequenceid=39, compaction requested=false
2011-09-02 09:33:57,516 DEBUG [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.HRegion(964): Finished snapshotting, commencing flushing stores
2011-09-02 09:33:57,516 DEBUG [RS_CLOSE_META-linux1.site,53487,1314927226948-0] regionserver.Store(418): closed info
2011-09-02 09:33:57,517 INFO  [RS_CLOSE_META-linux1.site,53487,1314927226948-0] regionserver.HRegion(554): Closed .META.,,1.1028785192
2011-09-02 09:33:57,517 DEBUG [RS_CLOSE_META-linux1.site,53487,1314927226948-0] handler.CloseRegionHandler(138): Closed region .META.,,1.1028785192
2011-09-02 09:33:57,564 INFO  [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.Store(494): Renaming flushed file at hdfs://localhost:47319/user/root/-ROOT-/70236052/.tmp/1398417344723896979 to hdfs://localhost:47319/user/root/-ROOT-/70236052/info/3663494863054324738
2011-09-02 09:33:57,582 INFO  [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.Store(504): Added hdfs://localhost:47319/user/root/-ROOT-/70236052/info/3663494863054324738, entries=2, sequenceid=40, memsize=464.0, filesize=504.0
2011-09-02 09:33:57,582 INFO  [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.HRegion(1026): Finished memstore flush of ~464.0 for region -ROOT-,,0.70236052 in 847ms, sequenceid=40, compaction requested=false
2011-09-02 09:33:57,583 DEBUG [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.Store(418): closed info
2011-09-02 09:33:57,583 INFO  [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.HRegion(554): Closed -ROOT-,,0.70236052
2011-09-02 09:33:57,583 DEBUG [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] handler.CloseRegionHandler(138): Closed region -ROOT-,,0.70236052
2011-09-02 09:33:57,700 INFO  [RegionServer:0;linux1.site,53487,1314927226948.leaseChecker] regionserver.Leases(124): RegionServer:0;linux1.site,53487,1314927226948.leaseChecker closing leases
2011-09-02 09:33:57,701 INFO  [RegionServer:0;linux1.site,53487,1314927226948.leaseChecker] regionserver.Leases(131): RegionServer:0;linux1.site,53487,1314927226948.leaseChecker closed leases
2011-09-02 09:33:58,230 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:33:58,460 INFO  [RegionServer:0;linux1.site,53487,1314927226948] regionserver.HRegionServer(709): Waiting on 1 regions to close
2011-09-02 09:33:58,460 DEBUG [RegionServer:0;linux1.site,53487,1314927226948] regionserver.HRegionServer(713): {5a8aaf25ba0a3afd05130cb9ccda5b47=test,ddd,1314927235514.5a8aaf25ba0a3afd05130cb9ccda5b47.}
2011-09-02 09:33:59,230 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:34:00,230 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:34:01,231 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:34:02,231 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:34:03,231 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:34:04,232 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:34:05,232 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
发件人: Ted Yu [mailto:yuzhihong@gmail.com]
发送时间: 2011年9月2日 10:58
收件人: dev@hbase.apache.org; bijieshan
抄送: Chenjian
主题: Re: About why did the unit tests get killed//Re: Build failed in Jenkins: hbase-0.90 #282

Only the tail of log is shown here.
Are you able to find the region from early part of the log ?
On Thu, Sep 1, 2011 at 7:41 PM, bijieshan <bi...@huawei.com>> wrote:
About this failure, I've seen it several times. I didn't see the detail logs for this one. But in my env, there's always some similar logs :

2011-09-02 09:33:57,517 INFO  [RS_CLOSE_META-linux1.site,53487,1314927226948-0] regionserver.HRegion(554): Closed .META.,,1.1028785192
2011-09-02 09:33:57,517 DEBUG [RS_CLOSE_META-linux1.site,53487,1314927226948-0] handler.CloseRegionHandler(138): Closed region .META.,,1.1028785192
2011-09-02 09:33:57,564 INFO  [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.Store(494): Renaming flushed file at hdfs://localhost:47319/user/root/-ROOT-/70236052/.tmp/1398417344723896979 to hdfs://localhost:47319/user/root/-ROOT-/70236052/info/3663494863054324738
2011-09-02 09:33:57,582 INFO  [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.Store(504): Added hdfs://localhost:47319/user/root/-ROOT-/70236052/info/3663494863054324738, entries=2, sequenceid=40, memsize=464.0, filesize=504.0
2011-09-02 09:33:57,582 INFO  [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.HRegion(1026): Finished memstore flush of ~464.0 for region -ROOT-,,0.70236052 in 847ms, sequenceid=40, compaction requested=false
2011-09-02 09:33:57,583 DEBUG [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.Store(418): closed info
2011-09-02 09:33:57,583 INFO  [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.HRegion(554): Closed -ROOT-,,0.70236052
2011-09-02 09:33:57,583 DEBUG [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] handler.CloseRegionHandler(138): Closed region -ROOT-,,0.70236052
2011-09-02 09:33:57,700 INFO  [RegionServer:0;linux1.site,53487,1314927226948.leaseChecker] regionserver.Leases(124): RegionServer:0;linux1.site,53487,1314927226948.leaseChecker closing leases
2011-09-02 09:33:57,701 INFO  [RegionServer:0;linux1.site,53487,1314927226948.leaseChecker] regionserver.Leases(131): RegionServer:0;linux1.site,53487,1314927226948.leaseChecker closed leases
2011-09-02 09:33:58,230 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:33:58,460 INFO  [RegionServer:0;linux1.site,53487,1314927226948] regionserver.HRegionServer(709): Waiting on 1 regions to close
2011-09-02 09:33:58,460 DEBUG [RegionServer:0;linux1.site,53487,1314927226948] regionserver.HRegionServer(713): {5a8aaf25ba0a3afd05130cb9ccda5b47=test,ddd,1314927235514.5a8aaf25ba0a3afd05130cb9ccda5b47.}
2011-09-02 09:33:59,230 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:34:00,230 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:34:01,231 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:34:02,231 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:34:03,231 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:34:04,232 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948
2011-09-02 09:34:05,232 INFO  [Master:0;linux1.site:40897] master.ServerManager(465): Waiting on regionserver(s) to go down linux1.site,53487,1314927226948

I've taken a detailed analysis. I think it happens in the below scenario:

One region is at the end of the opening process. But during the time, the cluster is shutting down. The user regions will be closed, and then .META., -ROOT-.
Step A: Cluster shut down.
Step B: Close user regions.
Step C: Close .META. and -ROOT-.

The new region's opening started before the step A, but finished after step B but before step C. So it will be added into onlineRegions.
Then the .META. and -ROOT- get closed. But the new region can't be closed anymore.

It's a race here.

Please correct me if am wrong.

Jieshan

-------------------------------------------
发件人: Apache Jenkins Server [mailto:jenkins@builds.apache.org<ma...@builds.apache.org>]
发送时间: 2011年8月31日 18:23
收件人: dev@hbase.apache.org<ma...@hbase.apache.org>
主题: Build failed in Jenkins: hbase-0.90 #282

See <https://builds.apache.org/job/hbase-0.90/282/changes>

Changes:

[tedyu] revert HBASE-4269 to see if 'Not a host:port pair' error still exists

------------------------------------------
[...truncated 1088 lines...]
Running org.apache.hadoop.hbase.regionserver.TestColumnSeeking
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 11.961 sec
Running org.apache.hadoop.hbase.client.TestMultipleTimestamps
Tests run: 8, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 73.359 sec
Running org.apache.hadoop.hbase.regionserver.TestMemStoreLAB
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.231 sec
Running org.apache.hadoop.hbase.TestZooKeeper
Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 74.577 sec
Running org.apache.hadoop.hbase.regionserver.wal.TestLogRolling
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 321.949 sec
Running org.apache.hadoop.hbase.io.hfile.TestCachedBlockQueue
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.018 sec
Running org.apache.hadoop.hbase.filter.TestPrefixFilter
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.018 sec
Running org.apache.hadoop.hbase.io.TestImmutableBytesWritable
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.hadoop.hbase.io.TestHeapSize
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.03 sec
Running org.apache.hadoop.hbase.rest.model.TestRowModel
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.037 sec
Running org.apache.hadoop.hbase.io.hfile.TestHFileSeek
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 4.851 sec
Running org.apache.hadoop.hbase.regionserver.TestStore
Tests run: 9, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.15 sec
Running org.apache.hadoop.hbase.zookeeper.TestHQuorumPeer
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.24 sec
Running org.apache.hadoop.hbase.regionserver.TestSplitTransactionOnCluster
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 32.021 sec
Running org.apache.hadoop.hbase.rest.TestScannersWithFilters
Tests run: 10, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 21.521 sec
Running org.apache.hadoop.hbase.io.hfile.TestHFilePerformance
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 5.599 sec
Running org.apache.hadoop.hbase.io.TestHbaseObjectWritable
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.061 sec
Running org.apache.hadoop.hbase.regionserver.handler.TestOpenRegionHandler
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.394 sec
Running org.apache.hadoop.hbase.regionserver.TestResettingCounters
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.241 sec
Running org.apache.hadoop.hbase.regionserver.wal.TestHLogSplit
Tests run: 23, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 192.013 sec
Running org.apache.hadoop.hbase.thrift.TestThriftServer
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 36.35 sec
Running org.apache.hadoop.hbase.regionserver.TestRpcMetrics
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.326 sec
Running org.apache.hadoop.hbase.filter.TestColumnPrefixFilter
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.918 sec
Running org.apache.hadoop.hbase.master.TestZKBasedOpenCloseRegion
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 29.065 sec
Running org.apache.hadoop.hbase.TestCompare
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.hadoop.hbase.regionserver.TestExplicitColumnTracker
Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.384 sec
Running org.apache.hadoop.hbase.util.TestEnvironmentEdgeManager
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.16 sec
Running org.apache.hadoop.hbase.io.TestHalfStoreFileReader
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.214 sec
Running org.apache.hadoop.hbase.util.TestDefaultEnvironmentEdge
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.hadoop.hbase.rest.TestTransform
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 43.369 sec
Running org.apache.hadoop.hbase.util.TestFSUtils
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 18.094 sec
Running org.apache.hadoop.hbase.security.TestUser
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.035 sec
Running org.apache.hadoop.hbase.master.TestMasterTransitions
Tests run: 3, Failures: 0, Errors: 0, Skipped: 3, Time elapsed: 81.51 sec
Running org.apache.hadoop.hbase.regionserver.TestScanWildcardColumnTracker
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.083 sec
Running org.apache.hadoop.hbase.regionserver.TestKeyValueSkipListSet
Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.02 sec
Running org.apache.hadoop.hbase.filter.TestPageFilter
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.hadoop.hbase.io.hfile.TestSeekTo
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.177 sec
Running org.apache.hadoop.hbase.filter.TestColumnPaginationFilter
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.hadoop.hbase.rest.TestStatusResource
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 18.673 sec
Running org.apache.hadoop.hbase.executor.TestExecutorService
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 2.177 sec
Running org.apache.hadoop.hbase.client.TestFromClientSide
Tests run: 42, Failures: 0, Errors: 0, Skipped: 3, Time elapsed: 172.022 sec
Running org.apache.hadoop.hbase.replication.TestReplication
Tests run: 1, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 21.697 sec <<< FAILURE!
Running org.apache.hadoop.hbase.regionserver.TestCompaction
Tests run: 9, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 148.063 sec
Running org.apache.hadoop.hbase.filter.TestSingleColumnValueFilter
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.033 sec
Running org.apache.hadoop.hbase.mapreduce.TestTimeRangeMapRed
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 51.801 sec
Running org.apache.hadoop.hbase.zookeeper.TestZooKeeperMainServerArg
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.025 sec
Running org.apache.hadoop.hbase.mapreduce.TestSimpleTotalOrderPartitioner
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.084 sec
Running org.apache.hadoop.hbase.master.TestClockSkewDetection
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.074 sec
Running org.apache.hadoop.hbase.mapreduce.TestHFileOutputFormat
Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 120.408 sec
Running org.apache.hadoop.hbase.master.TestMasterRestartAfterDisablingTable
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 18.634 sec
Running org.apache.hadoop.hbase.regionserver.TestFSErrorsExposed
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 48.239 sec
Running org.apache.hadoop.hbase.client.replication.TestReplicationAdmin
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 6.998 sec
Running org.apache.hadoop.hbase.regionserver.TestScanDeleteTracker
Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.114 sec
Running org.apache.hadoop.hbase.client.TestMetaScanner
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 16.519 sec
Running org.apache.hadoop.hbase.metrics.TestMetricsMBeanBase
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.033 sec
Running org.apache.hadoop.hbase.TestRegionRebalancing
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 82.071 sec
Running org.apache.hadoop.hbase.filter.TestSingleColumnValueExcludeFilter
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.hadoop.hbase.filter.TestInclusiveStopFilter
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.hadoop.hbase.rest.TestTableResource
Tests run: 8, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 49.068 sec
Running org.apache.hadoop.hbase.mapreduce.TestTableSplit
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.hadoop.hbase.TestHBaseTestingUtility
Tests run: 5, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 32.111 sec <<< FAILURE!
Running org.apache.hadoop.hbase.mapreduce.TestLoadIncrementalHFiles
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 32.447 sec
Running org.apache.hadoop.hbase.rest.TestSchemaResource
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 40.85 sec
Running org.apache.hadoop.hbase.regionserver.wal.TestWALReplay
Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 49.512 sec
Running org.apache.hadoop.hbase.regionserver.TestKeyValueScanFixture
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.057 sec
Running org.apache.hadoop.hbase.rest.model.TestTableListModel
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.125 sec
Running org.apache.hadoop.hbase.rest.model.TestColumnSchemaModel
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.03 sec
Running org.apache.hadoop.hbase.regionserver.TestStoreFile
Tests run: 7, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 38.014 sec
Running org.apache.hadoop.hbase.zookeeper.TestZooKeeperNodeTracker
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.354 sec
Running org.apache.hadoop.hbase.regionserver.wal.TestHLogMethods
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.425 sec
Running org.apache.hadoop.hbase.rest.model.TestScannerModel
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.132 sec
Running org.apache.hadoop.hbase.rest.TestVersionResource
Tests run: 7, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 18.463 sec
Running org.apache.hadoop.hbase.filter.TestFilter
Tests run: 18, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 3.239 sec
Running org.apache.hadoop.hbase.regionserver.TestWideScanner
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 17.808 sec
Running org.apache.hadoop.hbase.regionserver.TestSplitTransaction
Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 3.397 sec
Running org.apache.hadoop.hbase.replication.regionserver.TestReplicationSink
Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 24.442 sec
Running org.apache.hadoop.hbase.regionserver.TestGetClosestAtOrBefore
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 21.936 sec
Running org.apache.hadoop.hbase.regionserver.TestReadWriteConsistencyControl
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 10.03 sec
Running org.apache.hadoop.hbase.util.TestMergeTable
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 54.135 sec
Running org.apache.hadoop.hbase.rest.model.TestVersionModel
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.126 sec
Running org.apache.hadoop.hbase.rest.model.TestCellSetModel
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.133 sec
Running org.apache.hadoop.hbase.rest.client.TestRemoteTable
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 29.251 sec
Running org.apache.hadoop.hbase.rest.model.TestStorageClusterStatusModel
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.133 sec
Running org.apache.hadoop.hbase.avro.TestAvroServer
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 49.848 sec
Running org.apache.hadoop.hbase.TestFullLogReconstruction
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 58.015 sec
Running org.apache.hadoop.hbase.TestSerialization
Tests run: 19, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.067 sec
Running org.apache.hadoop.hbase.regionserver.TestKeyValueHeap
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.093 sec
Running org.apache.hadoop.hbase.regionserver.TestStoreScanner
Tests run: 14, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.032 sec
Running org.apache.hadoop.hbase.TestHMsg
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.021 sec
Running org.apache.hadoop.hbase.io.hfile.TestReseekTo
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.227 sec
Running org.apache.hadoop.hbase.regionserver.TestHRegionInfo
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.018 sec
Running org.apache.hadoop.hbase.util.TestIncrementingEnvironmentEdge
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.hadoop.hbase.util.TestKeying
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.hadoop.hbase.regionserver.TestScanner
Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 62.906 sec
Running org.apache.hadoop.hbase.util.TestHBaseFsck
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 42.867 sec
Running org.apache.hadoop.hbase.master.TestRestartCluster
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 48.994 sec
Running org.apache.hadoop.hbase.client.TestShell
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 249.925 sec
Running org.apache.hadoop.hbase.rest.model.TestTableInfoModel
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.129 sec
Running org.apache.hadoop.hbase.TestInfoServers
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 14.846 sec
Running org.apache.hadoop.hbase.master.TestLogsCleaner
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.156 sec
Running org.apache.hadoop.hbase.regionserver.TestMasterAddressManager
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.331 sec
Running org.apache.hadoop.hbase.catalog.TestCatalogTrackerOnCluster
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 143.307 sec
Running org.apache.hadoop.hbase.regionserver.TestQueryMatcher
Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.102 sec
Running org.apache.hadoop.hbase.zookeeper.TestZKTable
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.293 sec
Running org.apache.hadoop.hbase.client.TestAdmin
Tests run: 16, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 231.902 sec
Running org.apache.hadoop.hbase.regionserver.TestPriorityCompactionQueue
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.075 sec
Running org.apache.hadoop.hbase.util.TestMergeTool
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 19.144 sec
Running org.apache.hadoop.hbase.TestAcidGuarantees
Tests run: 3, Failures: 0, Errors: 0, Skipped: 3, Time elapsed: 0.015 sec
Running org.apache.hadoop.hbase.util.TestBase64
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.017 sec
Running org.apache.hadoop.hbase.regionserver.TestMemStore
Tests run: 21, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 47.72 sec
Running org.apache.hadoop.hbase.rest.TestScannerResource
Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 61.546 sec
Running org.apache.hadoop.hbase.io.hfile.TestLruBlockCache
Tests run: 7, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.056 sec
Running org.apache.hadoop.hbase.master.TestDeadServer
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.018 sec
Running org.apache.hadoop.hbase.rest.TestGzipFilter
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 36.159 sec
Running org.apache.hadoop.hbase.mapreduce.TestTableMapReduce
killed.
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 1:14:34.231s
[INFO] Finished at: Wed Aug 31 10:22:33 UTC 2011
[INFO] Final Memory: 31M/361M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.4.3:test (default-test) on project hbase: Error while executing forked tests.; nested exception is org.apache.maven.surefire.booter.shade.org.codehaus.plexus.util.cli.CommandLineException: Error while executing external command, process killed. Process timeout out after 900 seconds -> [Help 1]
[ERROR]
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR]
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoExecutionException
Build step 'Invoke top-level Maven targets' marked build as failure
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
Archiving artifacts
Recording test results


Re: About why did the unit tests get killed//Re: Build failed in Jenkins: hbase-0.90 #282

Posted by Ted Yu <yu...@gmail.com>.
Only the tail of log is shown here.
Are you able to find the region from early part of the log ?

On Thu, Sep 1, 2011 at 7:41 PM, bijieshan <bi...@huawei.com> wrote:

> About this failure, I've seen it several times. I didn't see the detail
> logs for this one. But in my env, there's always some similar logs :
>
> 2011-09-02 09:33:57,517 INFO
>  [RS_CLOSE_META-linux1.site,53487,1314927226948-0]
> regionserver.HRegion(554): Closed .META.,,1.1028785192
> 2011-09-02 09:33:57,517 DEBUG
> [RS_CLOSE_META-linux1.site,53487,1314927226948-0]
> handler.CloseRegionHandler(138): Closed region .META.,,1.1028785192
> 2011-09-02 09:33:57,564 INFO
>  [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.Store(494):
> Renaming flushed file at
> hdfs://localhost:47319/user/root/-ROOT-/70236052/.tmp/1398417344723896979 to
> hdfs://localhost:47319/user/root/-ROOT-/70236052/info/3663494863054324738
> 2011-09-02 09:33:57,582 INFO
>  [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.Store(504):
> Added
> hdfs://localhost:47319/user/root/-ROOT-/70236052/info/3663494863054324738,
> entries=2, sequenceid=40, memsize=464.0, filesize=504.0
> 2011-09-02 09:33:57,582 INFO
>  [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0]
> regionserver.HRegion(1026): Finished memstore flush of ~464.0 for region
> -ROOT-,,0.70236052 in 847ms, sequenceid=40, compaction requested=false
> 2011-09-02 09:33:57,583 DEBUG
> [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0] regionserver.Store(418):
> closed info
> 2011-09-02 09:33:57,583 INFO
>  [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0]
> regionserver.HRegion(554): Closed -ROOT-,,0.70236052
> 2011-09-02 09:33:57,583 DEBUG
> [RS_CLOSE_ROOT-linux1.site,53487,1314927226948-0]
> handler.CloseRegionHandler(138): Closed region -ROOT-,,0.70236052
> 2011-09-02 09:33:57,700 INFO
>  [RegionServer:0;linux1.site,53487,1314927226948.leaseChecker]
> regionserver.Leases(124):
> RegionServer:0;linux1.site,53487,1314927226948.leaseChecker closing leases
> 2011-09-02 09:33:57,701 INFO
>  [RegionServer:0;linux1.site,53487,1314927226948.leaseChecker]
> regionserver.Leases(131):
> RegionServer:0;linux1.site,53487,1314927226948.leaseChecker closed leases
> 2011-09-02 09:33:58,230 INFO  [Master:0;linux1.site:40897]
> master.ServerManager(465): Waiting on regionserver(s) to go down
> linux1.site,53487,1314927226948
> 2011-09-02 09:33:58,460 INFO
>  [RegionServer:0;linux1.site,53487,1314927226948]
> regionserver.HRegionServer(709): Waiting on 1 regions to close
> 2011-09-02 09:33:58,460 DEBUG
> [RegionServer:0;linux1.site,53487,1314927226948]
> regionserver.HRegionServer(713):
> {5a8aaf25ba0a3afd05130cb9ccda5b47=test,ddd,1314927235514.5a8aaf25ba0a3afd05130cb9ccda5b47.}
> 2011-09-02 09:33:59,230 INFO  [Master:0;linux1.site:40897]
> master.ServerManager(465): Waiting on regionserver(s) to go down
> linux1.site,53487,1314927226948
> 2011-09-02 09:34:00,230 INFO  [Master:0;linux1.site:40897]
> master.ServerManager(465): Waiting on regionserver(s) to go down
> linux1.site,53487,1314927226948
> 2011-09-02 09:34:01,231 INFO  [Master:0;linux1.site:40897]
> master.ServerManager(465): Waiting on regionserver(s) to go down
> linux1.site,53487,1314927226948
> 2011-09-02 09:34:02,231 INFO  [Master:0;linux1.site:40897]
> master.ServerManager(465): Waiting on regionserver(s) to go down
> linux1.site,53487,1314927226948
> 2011-09-02 09:34:03,231 INFO  [Master:0;linux1.site:40897]
> master.ServerManager(465): Waiting on regionserver(s) to go down
> linux1.site,53487,1314927226948
> 2011-09-02 09:34:04,232 INFO  [Master:0;linux1.site:40897]
> master.ServerManager(465): Waiting on regionserver(s) to go down
> linux1.site,53487,1314927226948
> 2011-09-02 09:34:05,232 INFO  [Master:0;linux1.site:40897]
> master.ServerManager(465): Waiting on regionserver(s) to go down
> linux1.site,53487,1314927226948
>
> I've taken a detailed analysis. I think it happens in the below scenario:
>
> One region is at the end of the opening process. But during the time, the
> cluster is shutting down. The user regions will be closed, and then .META.,
> -ROOT-.
> Step A: Cluster shut down.
> Step B: Close user regions.
> Step C: Close .META. and -ROOT-.
>
> The new region's opening started before the step A, but finished after step
> B but before step C. So it will be added into onlineRegions.
> Then the .META. and -ROOT- get closed. But the new region can't be closed
> anymore.
>
> It's a race here.
>
> Please correct me if am wrong.
>
> Jieshan
>
> -------------------------------------------
> 发件人: Apache Jenkins Server [mailto:jenkins@builds.apache.org]
> 发送时间: 2011年8月31日 18:23
> 收件人: dev@hbase.apache.org
> 主题: Build failed in Jenkins: hbase-0.90 #282
>
> See <https://builds.apache.org/job/hbase-0.90/282/changes>
>
> Changes:
>
> [tedyu] revert HBASE-4269 to see if 'Not a host:port pair' error still
> exists
>
> ------------------------------------------
> [...truncated 1088 lines...]
> Running org.apache.hadoop.hbase.regionserver.TestColumnSeeking
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 11.961 sec
> Running org.apache.hadoop.hbase.client.TestMultipleTimestamps
> Tests run: 8, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 73.359 sec
> Running org.apache.hadoop.hbase.regionserver.TestMemStoreLAB
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.231 sec
> Running org.apache.hadoop.hbase.TestZooKeeper
> Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 74.577 sec
> Running org.apache.hadoop.hbase.regionserver.wal.TestLogRolling
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 321.949 sec
> Running org.apache.hadoop.hbase.io.hfile.TestCachedBlockQueue
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.018 sec
> Running org.apache.hadoop.hbase.filter.TestPrefixFilter
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.018 sec
> Running org.apache.hadoop.hbase.io.TestImmutableBytesWritable
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
> Running org.apache.hadoop.hbase.io.TestHeapSize
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.03 sec
> Running org.apache.hadoop.hbase.rest.model.TestRowModel
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.037 sec
> Running org.apache.hadoop.hbase.io.hfile.TestHFileSeek
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 4.851 sec
> Running org.apache.hadoop.hbase.regionserver.TestStore
> Tests run: 9, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.15 sec
> Running org.apache.hadoop.hbase.zookeeper.TestHQuorumPeer
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.24 sec
> Running org.apache.hadoop.hbase.regionserver.TestSplitTransactionOnCluster
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 32.021 sec
> Running org.apache.hadoop.hbase.rest.TestScannersWithFilters
> Tests run: 10, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 21.521 sec
> Running org.apache.hadoop.hbase.io.hfile.TestHFilePerformance
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 5.599 sec
> Running org.apache.hadoop.hbase.io.TestHbaseObjectWritable
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.061 sec
> Running org.apache.hadoop.hbase.regionserver.handler.TestOpenRegionHandler
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.394 sec
> Running org.apache.hadoop.hbase.regionserver.TestResettingCounters
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.241 sec
> Running org.apache.hadoop.hbase.regionserver.wal.TestHLogSplit
> Tests run: 23, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 192.013
> sec
> Running org.apache.hadoop.hbase.thrift.TestThriftServer
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 36.35 sec
> Running org.apache.hadoop.hbase.regionserver.TestRpcMetrics
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.326 sec
> Running org.apache.hadoop.hbase.filter.TestColumnPrefixFilter
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.918 sec
> Running org.apache.hadoop.hbase.master.TestZKBasedOpenCloseRegion
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 29.065 sec
> Running org.apache.hadoop.hbase.TestCompare
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
> Running org.apache.hadoop.hbase.regionserver.TestExplicitColumnTracker
> Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.384 sec
> Running org.apache.hadoop.hbase.util.TestEnvironmentEdgeManager
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.16 sec
> Running org.apache.hadoop.hbase.io.TestHalfStoreFileReader
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.214 sec
> Running org.apache.hadoop.hbase.util.TestDefaultEnvironmentEdge
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
> Running org.apache.hadoop.hbase.rest.TestTransform
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 43.369 sec
> Running org.apache.hadoop.hbase.util.TestFSUtils
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 18.094 sec
> Running org.apache.hadoop.hbase.security.TestUser
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.035 sec
> Running org.apache.hadoop.hbase.master.TestMasterTransitions
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 3, Time elapsed: 81.51 sec
> Running org.apache.hadoop.hbase.regionserver.TestScanWildcardColumnTracker
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.083 sec
> Running org.apache.hadoop.hbase.regionserver.TestKeyValueSkipListSet
> Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.02 sec
> Running org.apache.hadoop.hbase.filter.TestPageFilter
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
> Running org.apache.hadoop.hbase.io.hfile.TestSeekTo
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.177 sec
> Running org.apache.hadoop.hbase.filter.TestColumnPaginationFilter
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
> Running org.apache.hadoop.hbase.rest.TestStatusResource
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 18.673 sec
> Running org.apache.hadoop.hbase.executor.TestExecutorService
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 2.177 sec
> Running org.apache.hadoop.hbase.client.TestFromClientSide
> Tests run: 42, Failures: 0, Errors: 0, Skipped: 3, Time elapsed: 172.022
> sec
> Running org.apache.hadoop.hbase.replication.TestReplication
> Tests run: 1, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 21.697 sec
> <<< FAILURE!
> Running org.apache.hadoop.hbase.regionserver.TestCompaction
> Tests run: 9, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 148.063 sec
> Running org.apache.hadoop.hbase.filter.TestSingleColumnValueFilter
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.033 sec
> Running org.apache.hadoop.hbase.mapreduce.TestTimeRangeMapRed
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 51.801 sec
> Running org.apache.hadoop.hbase.zookeeper.TestZooKeeperMainServerArg
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.025 sec
> Running org.apache.hadoop.hbase.mapreduce.TestSimpleTotalOrderPartitioner
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.084 sec
> Running org.apache.hadoop.hbase.master.TestClockSkewDetection
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.074 sec
> Running org.apache.hadoop.hbase.mapreduce.TestHFileOutputFormat
> Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 120.408 sec
> Running org.apache.hadoop.hbase.master.TestMasterRestartAfterDisablingTable
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 18.634 sec
> Running org.apache.hadoop.hbase.regionserver.TestFSErrorsExposed
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 48.239 sec
> Running org.apache.hadoop.hbase.client.replication.TestReplicationAdmin
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 6.998 sec
> Running org.apache.hadoop.hbase.regionserver.TestScanDeleteTracker
> Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.114 sec
> Running org.apache.hadoop.hbase.client.TestMetaScanner
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 16.519 sec
> Running org.apache.hadoop.hbase.metrics.TestMetricsMBeanBase
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.033 sec
> Running org.apache.hadoop.hbase.TestRegionRebalancing
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 82.071 sec
> Running org.apache.hadoop.hbase.filter.TestSingleColumnValueExcludeFilter
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
> Running org.apache.hadoop.hbase.filter.TestInclusiveStopFilter
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
> Running org.apache.hadoop.hbase.rest.TestTableResource
> Tests run: 8, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 49.068 sec
> Running org.apache.hadoop.hbase.mapreduce.TestTableSplit
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
> Running org.apache.hadoop.hbase.TestHBaseTestingUtility
> Tests run: 5, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 32.111 sec
> <<< FAILURE!
> Running org.apache.hadoop.hbase.mapreduce.TestLoadIncrementalHFiles
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 32.447 sec
> Running org.apache.hadoop.hbase.rest.TestSchemaResource
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 40.85 sec
> Running org.apache.hadoop.hbase.regionserver.wal.TestWALReplay
> Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 49.512 sec
> Running org.apache.hadoop.hbase.regionserver.TestKeyValueScanFixture
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.057 sec
> Running org.apache.hadoop.hbase.rest.model.TestTableListModel
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.125 sec
> Running org.apache.hadoop.hbase.rest.model.TestColumnSchemaModel
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.03 sec
> Running org.apache.hadoop.hbase.regionserver.TestStoreFile
> Tests run: 7, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 38.014 sec
> Running org.apache.hadoop.hbase.zookeeper.TestZooKeeperNodeTracker
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.354 sec
> Running org.apache.hadoop.hbase.regionserver.wal.TestHLogMethods
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.425 sec
> Running org.apache.hadoop.hbase.rest.model.TestScannerModel
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.132 sec
> Running org.apache.hadoop.hbase.rest.TestVersionResource
> Tests run: 7, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 18.463 sec
> Running org.apache.hadoop.hbase.filter.TestFilter
> Tests run: 18, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 3.239 sec
> Running org.apache.hadoop.hbase.regionserver.TestWideScanner
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 17.808 sec
> Running org.apache.hadoop.hbase.regionserver.TestSplitTransaction
> Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 3.397 sec
> Running
> org.apache.hadoop.hbase.replication.regionserver.TestReplicationSink
> Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 24.442 sec
> Running org.apache.hadoop.hbase.regionserver.TestGetClosestAtOrBefore
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 21.936 sec
> Running
> org.apache.hadoop.hbase.regionserver.TestReadWriteConsistencyControl
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 10.03 sec
> Running org.apache.hadoop.hbase.util.TestMergeTable
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 54.135 sec
> Running org.apache.hadoop.hbase.rest.model.TestVersionModel
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.126 sec
> Running org.apache.hadoop.hbase.rest.model.TestCellSetModel
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.133 sec
> Running org.apache.hadoop.hbase.rest.client.TestRemoteTable
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 29.251 sec
> Running org.apache.hadoop.hbase.rest.model.TestStorageClusterStatusModel
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.133 sec
> Running org.apache.hadoop.hbase.avro.TestAvroServer
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 49.848 sec
> Running org.apache.hadoop.hbase.TestFullLogReconstruction
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 58.015 sec
> Running org.apache.hadoop.hbase.TestSerialization
> Tests run: 19, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.067 sec
> Running org.apache.hadoop.hbase.regionserver.TestKeyValueHeap
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.093 sec
> Running org.apache.hadoop.hbase.regionserver.TestStoreScanner
> Tests run: 14, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.032 sec
> Running org.apache.hadoop.hbase.TestHMsg
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.021 sec
> Running org.apache.hadoop.hbase.io.hfile.TestReseekTo
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.227 sec
> Running org.apache.hadoop.hbase.regionserver.TestHRegionInfo
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.018 sec
> Running org.apache.hadoop.hbase.util.TestIncrementingEnvironmentEdge
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
> Running org.apache.hadoop.hbase.util.TestKeying
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
> Running org.apache.hadoop.hbase.regionserver.TestScanner
> Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 62.906 sec
> Running org.apache.hadoop.hbase.util.TestHBaseFsck
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 42.867 sec
> Running org.apache.hadoop.hbase.master.TestRestartCluster
> Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 48.994 sec
> Running org.apache.hadoop.hbase.client.TestShell
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 249.925 sec
> Running org.apache.hadoop.hbase.rest.model.TestTableInfoModel
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.129 sec
> Running org.apache.hadoop.hbase.TestInfoServers
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 14.846 sec
> Running org.apache.hadoop.hbase.master.TestLogsCleaner
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.156 sec
> Running org.apache.hadoop.hbase.regionserver.TestMasterAddressManager
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.331 sec
> Running org.apache.hadoop.hbase.catalog.TestCatalogTrackerOnCluster
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 143.307 sec
> Running org.apache.hadoop.hbase.regionserver.TestQueryMatcher
> Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.102 sec
> Running org.apache.hadoop.hbase.zookeeper.TestZKTable
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.293 sec
> Running org.apache.hadoop.hbase.client.TestAdmin
> Tests run: 16, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 231.902
> sec
> Running org.apache.hadoop.hbase.regionserver.TestPriorityCompactionQueue
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.075 sec
> Running org.apache.hadoop.hbase.util.TestMergeTool
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 19.144 sec
> Running org.apache.hadoop.hbase.TestAcidGuarantees
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 3, Time elapsed: 0.015 sec
> Running org.apache.hadoop.hbase.util.TestBase64
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.017 sec
> Running org.apache.hadoop.hbase.regionserver.TestMemStore
> Tests run: 21, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 47.72 sec
> Running org.apache.hadoop.hbase.rest.TestScannerResource
> Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 61.546 sec
> Running org.apache.hadoop.hbase.io.hfile.TestLruBlockCache
> Tests run: 7, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.056 sec
> Running org.apache.hadoop.hbase.master.TestDeadServer
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.018 sec
> Running org.apache.hadoop.hbase.rest.TestGzipFilter
> Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 36.159 sec
> Running org.apache.hadoop.hbase.mapreduce.TestTableMapReduce
> killed.
> [INFO]
> ------------------------------------------------------------------------
> [INFO] BUILD FAILURE
> [INFO]
> ------------------------------------------------------------------------
> [INFO] Total time: 1:14:34.231s
> [INFO] Finished at: Wed Aug 31 10:22:33 UTC 2011
> [INFO] Final Memory: 31M/361M
> [INFO]
> ------------------------------------------------------------------------
> [ERROR] Failed to execute goal
> org.apache.maven.plugins:maven-surefire-plugin:2.4.3:test (default-test) on
> project hbase: Error while executing forked tests.; nested exception is
> org.apache.maven.surefire.booter.shade.org.codehaus.plexus.util.cli.CommandLineException:
> Error while executing external command, process killed. Process timeout out
> after 900 seconds -> [Help 1]
> [ERROR]
> [ERROR] To see the full stack trace of the errors, re-run Maven with the -e
> switch.
> [ERROR] Re-run Maven using the -X switch to enable full debug logging.
> [ERROR]
> [ERROR] For more information about the errors and possible solutions,
> please read the following articles:
> [ERROR] [Help 1]
> http://cwiki.apache.org/confluence/display/MAVEN/MojoExecutionException
> Build step 'Invoke top-level Maven targets' marked build as failure
> [locks-and-latches] Releasing all the locks
> [locks-and-latches] All the locks released
> Archiving artifacts
> Recording test results
>
>