• Home
• com.github.heiqs
• crashFinder
• 2.1.2
• source code
• log-stacktrace.txt

×

Project download

Many resources are needed to download a project. Please understand that we have to compensate our server costs. Thank you in advance.
Project price only 1 $

You can buy this project and download/modify it how often you want.

resources.log-stacktrace.txt Maven / Gradle / Ivy

Formatting using clusterid: testClusterID
2015-10-19 20:03:28,647 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:28,674 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:28,697 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:28,698 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:28,699 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:28,699 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:28,699 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:28,700 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:28,700 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:28,701 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:29,123 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:29,124 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:29,125 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:29,126 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:29,174 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:29,303 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:29,324 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:29,325 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:29,326 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:29,785 INFO  namenode.NNStorage (NNStorage.java:format(531)) - Storage directory /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1 has been successfully formatted.
2015-10-19 20:03:29,816 INFO  namenode.FSImage (FSImageFormat.java:save(504)) - Saving image file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/fsimage.ckpt_0000000000000000000 using no compression
2015-10-19 20:03:29,859 INFO  namenode.FSImage (FSImageFormat.java:save(531)) - Image file of size 120 saved in 0 seconds.
2015-10-19 20:03:29,980 INFO  namenode.NNStorageRetentionManager (NNStorageRetentionManager.java:getImageTxIdToRetain(133)) - Going to retain 1 images with txid >= 0
2015-10-19 20:03:30,371 INFO  impl.MetricsConfig (MetricsConfig.java:loadFirst(112)) - loaded properties from hadoop-metrics2.properties
2015-10-19 20:03:30,663 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:startTimer(343)) - Scheduled snapshot period at 10 second(s).
2015-10-19 20:03:30,664 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:start(183)) - NameNode metrics system started
2015-10-19 20:03:31,006 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(402)) - Only one image storage directory (dfs.namenode.name.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:31,008 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(407)) - Only one namespace edits storage directory (dfs.namenode.edits.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:31,015 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:31,016 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:31,021 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:31,024 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:31,025 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:31,026 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:31,027 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:31,028 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:31,030 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:31,031 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:31,032 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:31,033 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:31,034 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:31,037 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:31,038 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:31,039 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:31,040 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:31,041 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:31,043 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:31,067 INFO  common.Storage (Storage.java:tryLock(654)) - Lock on /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/in_use.lock acquired by nodename 5544@hadoop-VM
2015-10-19 20:03:31,079 INFO  namenode.FileJournalManager (FileJournalManager.java:recoverUnfinalizedSegments(284)) - Recovering unfinalized segments in /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current
2015-10-19 20:03:31,091 INFO  namenode.FSImage (FSImage.java:loadFSImage(628)) - No edit log streams selected.
2015-10-19 20:03:31,098 INFO  namenode.FSImage (FSImageFormat.java:load(168)) - Loading image file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/fsimage_0000000000000000000 using no compression
2015-10-19 20:03:31,099 INFO  namenode.FSImage (FSImageFormat.java:load(171)) - Number of files = 1
2015-10-19 20:03:31,100 INFO  namenode.FSImage (FSImageFormat.java:loadFilesUnderConstruction(361)) - Number of files under construction = 0
2015-10-19 20:03:31,101 INFO  namenode.FSImage (FSImageFormat.java:load(193)) - Image file of size 120 loaded in 0 seconds.
2015-10-19 20:03:31,103 INFO  namenode.FSImage (FSImage.java:loadFSImage(771)) - Loaded image for txid 0 from /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/fsimage_0000000000000000000
2015-10-19 20:03:31,119 INFO  namenode.FSEditLog (FSEditLog.java:startLogSegment(949)) - Starting log segment at 1
2015-10-19 20:03:31,339 INFO  namenode.NameCache (NameCache.java:initialized(143)) - initialized with 0 entries 0 lookups
2015-10-19 20:03:31,340 INFO  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(424)) - Finished loading FSImage in 296 msecs
2015-10-19 20:03:32,115 INFO  ipc.Server (Server.java:run(483)) - Starting Socket Reader #1 for port 50563
2015-10-19 20:03:32,214 INFO  namenode.FSNamesystem (FSNamesystem.java:registerMBean(4651)) - Registered FSNamesystemState MBean
2015-10-19 20:03:32,269 INFO  namenode.FSNamesystem (FSNamesystem.java:getCompleteBlocksTotal(4329)) - Number of blocks under construction: 0
2015-10-19 20:03:32,271 INFO  namenode.FSNamesystem (FSNamesystem.java:initializeReplQueues(3870)) - initializing replication queues
2015-10-19 20:03:32,291 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2221)) - Total number of blocks            = 0
2015-10-19 20:03:32,292 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2222)) - Number of invalid blocks          = 0
2015-10-19 20:03:32,293 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2223)) - Number of under-replicated blocks = 0
2015-10-19 20:03:32,294 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2224)) - Number of  over-replicated blocks = 0
2015-10-19 20:03:32,294 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2226)) - Number of blocks being written    = 0
2015-10-19 20:03:32,295 INFO  hdfs.StateChange (FSNamesystem.java:initializeReplQueues(3875)) - STATE* Replication Queue initialization scan for invalid, over- and under-replicated blocks completed in 24 msec
2015-10-19 20:03:32,295 INFO  hdfs.StateChange (FSNamesystem.java:leave(3847)) - STATE* Leaving safe mode after 1 secs.
2015-10-19 20:03:32,297 INFO  hdfs.StateChange (FSNamesystem.java:leave(3857)) - STATE* Network topology has 0 racks and 0 datanodes
2015-10-19 20:03:32,297 INFO  hdfs.StateChange (FSNamesystem.java:leave(3860)) - STATE* UnderReplicatedBlocks has 0 blocks
2015-10-19 20:03:32,663 INFO  mortbay.log (Slf4jLog.java:info(67)) - Logging to org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via org.mortbay.log.Slf4jLog
2015-10-19 20:03:32,872 INFO  http.HttpServer (HttpServer.java:addGlobalFilter(499)) - Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
2015-10-19 20:03:32,878 INFO  http.HttpServer (HttpServer.java:addFilter(477)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context hdfs
2015-10-19 20:03:32,880 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context logs
2015-10-19 20:03:32,881 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context static
2015-10-19 20:03:32,918 INFO  http.HttpServer (WebHdfsFileSystem.java:isEnabled(142)) - dfs.webhdfs.enabled = false
2015-10-19 20:03:32,947 INFO  http.HttpServer (HttpServer.java:start(657)) - Jetty bound to port 47825
2015-10-19 20:03:32,948 INFO  mortbay.log (Slf4jLog.java:info(67)) - jetty-6.1.26
2015-10-19 20:03:33,349 INFO  mortbay.log (Slf4jLog.java:info(67)) - Started SelectChannelConnector@hadoop-VM:47825
2015-10-19 20:03:33,350 INFO  namenode.NameNode (NameNode.java:setHttpServerAddress(394)) - Web-server up at: hadoop-VM:47825
2015-10-19 20:03:33,351 INFO  ipc.Server (Server.java:run(776)) - IPC Server Responder: starting
2015-10-19 20:03:33,357 INFO  ipc.Server (Server.java:run(607)) - IPC Server listener on 50563: starting
2015-10-19 20:03:33,374 INFO  namenode.NameNode (NameNode.java:startCommonServices(491)) - NameNode up at: hadoop-VM/127.0.1.1:50563
2015-10-19 20:03:33,374 INFO  namenode.FSNamesystem (FSNamesystem.java:startActiveServices(619)) - Starting services required for active state
Formatting using clusterid: testClusterID
2015-10-19 20:03:33,432 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:33,433 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:33,436 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:33,438 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:33,439 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:33,439 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:33,440 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:33,441 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:33,441 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:33,442 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:33,442 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:33,443 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:33,444 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:33,445 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:33,446 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:33,447 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:33,448 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:33,448 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:33,449 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:33,463 INFO  namenode.NNStorage (NNStorage.java:format(531)) - Storage directory /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2 has been successfully formatted.
2015-10-19 20:03:33,466 INFO  namenode.FSImage (FSImageFormat.java:save(504)) - Saving image file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/fsimage.ckpt_0000000000000000000 using no compression
2015-10-19 20:03:33,472 INFO  namenode.FSImage (FSImageFormat.java:save(531)) - Image file of size 120 saved in 0 seconds.
2015-10-19 20:03:33,480 INFO  namenode.NNStorageRetentionManager (NNStorageRetentionManager.java:getImageTxIdToRetain(133)) - Going to retain 1 images with txid >= 0
2015-10-19 20:03:33,481 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(151)) - NameNode metrics system started (again)
2015-10-19 20:03:33,494 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(402)) - Only one image storage directory (dfs.namenode.name.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:33,495 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(407)) - Only one namespace edits storage directory (dfs.namenode.edits.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:33,496 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:33,497 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:33,499 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:33,500 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:33,501 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:33,501 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:33,502 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:33,502 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:33,502 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:33,503 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:33,503 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:33,504 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:33,505 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:33,506 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:33,506 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:33,507 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:33,508 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:33,508 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:33,509 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:33,514 INFO  common.Storage (Storage.java:tryLock(654)) - Lock on /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/in_use.lock acquired by nodename 5544@hadoop-VM
2015-10-19 20:03:33,518 INFO  namenode.FileJournalManager (FileJournalManager.java:recoverUnfinalizedSegments(284)) - Recovering unfinalized segments in /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current
2015-10-19 20:03:33,520 INFO  namenode.FSImage (FSImage.java:loadFSImage(628)) - No edit log streams selected.
2015-10-19 20:03:33,522 INFO  namenode.FSImage (FSImageFormat.java:load(168)) - Loading image file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/fsimage_0000000000000000000 using no compression
2015-10-19 20:03:33,522 INFO  namenode.FSImage (FSImageFormat.java:load(171)) - Number of files = 1
2015-10-19 20:03:33,523 INFO  namenode.FSImage (FSImageFormat.java:loadFilesUnderConstruction(361)) - Number of files under construction = 0
2015-10-19 20:03:33,523 INFO  namenode.FSImage (FSImageFormat.java:load(193)) - Image file of size 120 loaded in 0 seconds.
2015-10-19 20:03:33,524 INFO  namenode.FSImage (FSImage.java:loadFSImage(771)) - Loaded image for txid 0 from /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/fsimage_0000000000000000000
2015-10-19 20:03:33,525 INFO  namenode.FSEditLog (FSEditLog.java:startLogSegment(949)) - Starting log segment at 1
2015-10-19 20:03:33,544 INFO  namenode.NameCache (NameCache.java:initialized(143)) - initialized with 0 entries 0 lookups
2015-10-19 20:03:33,544 INFO  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(424)) - Finished loading FSImage in 35 msecs
2015-10-19 20:03:33,547 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:33,547 INFO  namenode.FSEditLog (FSEditLog.java:endCurrentLogSegment(992)) - Ending log segment 1
2015-10-19 20:03:33,553 INFO  namenode.FSEditLog (FSEditLog.java:printStatistics(650)) - Number of transactions: 2 Total time for transactions(ms): 0Number of transactions batched in Syncs: 0 Number of syncs: 3 SyncTimes(ms): 16 
2015-10-19 20:03:33,556 INFO  namenode.FileJournalManager (FileJournalManager.java:finalizeLogSegment(122)) - Finalizing edits file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_inprogress_0000000000000000001 -> /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000001-0000000000000000002
2015-10-19 20:03:33,558 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:33,559 INFO  namenode.FSNamesystem (FSNamesystem.java:stopStandbyServices(743)) - Stopping services started for standby state
2015-10-19 20:03:33,560 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(151)) - NameNode metrics system started (again)
2015-10-19 20:03:33,572 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(402)) - Only one image storage directory (dfs.namenode.name.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:33,573 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(407)) - Only one namespace edits storage directory (dfs.namenode.edits.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:33,574 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:33,575 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:33,590 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:33,592 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:33,592 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:33,593 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:33,593 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:33,593 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:33,597 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:33,598 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:33,599 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:33,599 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:33,600 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:33,600 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:33,605 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:33,609 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:33,611 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:33,612 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:33,612 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:33,627 INFO  common.Storage (Storage.java:tryLock(654)) - Lock on /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/in_use.lock acquired by nodename 5544@hadoop-VM
2015-10-19 20:03:33,631 INFO  namenode.FileJournalManager (FileJournalManager.java:recoverUnfinalizedSegments(284)) - Recovering unfinalized segments in /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current
2015-10-19 20:03:33,666 INFO  namenode.FSImage (FSImageFormat.java:load(168)) - Loading image file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/fsimage_0000000000000000000 using no compression
2015-10-19 20:03:33,667 INFO  namenode.FSImage (FSImageFormat.java:load(171)) - Number of files = 1
2015-10-19 20:03:33,668 INFO  namenode.FSImage (FSImageFormat.java:loadFilesUnderConstruction(361)) - Number of files under construction = 0
2015-10-19 20:03:33,669 INFO  namenode.FSImage (FSImageFormat.java:load(193)) - Image file of size 120 loaded in 0 seconds.
2015-10-19 20:03:33,670 INFO  namenode.FSImage (FSImage.java:loadFSImage(771)) - Loaded image for txid 0 from /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/fsimage_0000000000000000000
2015-10-19 20:03:33,670 INFO  namenode.FSImage (FSImage.java:loadEdits(712)) - Reading org.apache.hadoop.hdfs.server.namenode.RedundantEditLogInputStream@387dc030 expecting start txid #1
2015-10-19 20:03:33,672 INFO  namenode.EditLogInputStream (RedundantEditLogInputStream.java:nextOp(177)) - Fast-forwarding stream '/home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000001-0000000000000000002' to transaction ID 1
2015-10-19 20:03:33,682 INFO  namenode.FSImage (FSEditLogLoader.java:loadFSEdits(93)) - Edits file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000001-0000000000000000002 of size 30 edits # 2 loaded in 0 seconds.
2015-10-19 20:03:33,684 INFO  namenode.FSEditLog (FSEditLog.java:startLogSegment(949)) - Starting log segment at 3
2015-10-19 20:03:33,705 INFO  namenode.NameCache (NameCache.java:initialized(143)) - initialized with 0 entries 0 lookups
2015-10-19 20:03:33,706 INFO  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(424)) - Finished loading FSImage in 93 msecs
2015-10-19 20:03:33,744 INFO  ipc.Server (Server.java:run(483)) - Starting Socket Reader #1 for port 51329
2015-10-19 20:03:33,761 INFO  namenode.FSNamesystem (FSNamesystem.java:registerMBean(4651)) - Registered FSNamesystemState MBean
2015-10-19 20:03:33,779 INFO  namenode.FSNamesystem (FSNamesystem.java:getCompleteBlocksTotal(4329)) - Number of blocks under construction: 0
2015-10-19 20:03:33,779 INFO  namenode.FSNamesystem (FSNamesystem.java:initializeReplQueues(3870)) - initializing replication queues
2015-10-19 20:03:33,786 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2221)) - Total number of blocks            = 0
2015-10-19 20:03:33,788 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2222)) - Number of invalid blocks          = 0
2015-10-19 20:03:33,789 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2223)) - Number of under-replicated blocks = 0
2015-10-19 20:03:33,790 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2224)) - Number of  over-replicated blocks = 0
2015-10-19 20:03:33,790 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2226)) - Number of blocks being written    = 0
2015-10-19 20:03:33,791 INFO  hdfs.StateChange (FSNamesystem.java:initializeReplQueues(3875)) - STATE* Replication Queue initialization scan for invalid, over- and under-replicated blocks completed in 11 msec
2015-10-19 20:03:33,791 INFO  hdfs.StateChange (FSNamesystem.java:leave(3847)) - STATE* Leaving safe mode after 0 secs.
2015-10-19 20:03:33,792 INFO  hdfs.StateChange (FSNamesystem.java:leave(3857)) - STATE* Network topology has 0 racks and 0 datanodes
2015-10-19 20:03:33,792 INFO  hdfs.StateChange (FSNamesystem.java:leave(3860)) - STATE* UnderReplicatedBlocks has 0 blocks
2015-10-19 20:03:33,819 INFO  http.HttpServer (HttpServer.java:addGlobalFilter(499)) - Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
2015-10-19 20:03:33,822 INFO  http.HttpServer (HttpServer.java:addFilter(477)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context hdfs
2015-10-19 20:03:33,822 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context static
2015-10-19 20:03:33,823 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context logs
2015-10-19 20:03:33,827 INFO  http.HttpServer (WebHdfsFileSystem.java:isEnabled(142)) - dfs.webhdfs.enabled = false
2015-10-19 20:03:33,834 INFO  http.HttpServer (HttpServer.java:start(660)) - HttpServer.start() threw a non Bind IOException
java.net.BindException: Port in use: hadoop-VM:47825
	at org.apache.hadoop.http.HttpServer.openListener(HttpServer.java:706)
	at org.apache.hadoop.http.HttpServer.start(HttpServer.java:656)
	at org.apache.hadoop.hdfs.server.namenode.NameNodeHttpServer.start(NameNodeHttpServer.java:159)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.startHttpServer(NameNode.java:536)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.startCommonServices(NameNode.java:480)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.initialize(NameNode.java:443)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.(NameNode.java:597)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.(NameNode.java:578)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.createNameNode(NameNode.java:1117)
	at org.apache.hadoop.hdfs.TestHDFSServerPorts.canStartNameNode(TestHDFSServerPorts.java:187)
	at org.apache.hadoop.hdfs.TestHDFSServerPorts.runTestNameNodePorts(TestHDFSServerPorts.java:277)
	at org.apache.hadoop.hdfs.TestHDFSServerPorts.testNameNodePorts(TestHDFSServerPorts.java:256)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
	at org.junit.runners.BlockJUnit4ClassRunner.runNotIgnored(BlockJUnit4ClassRunner.java:79)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:71)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:49)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
	at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:264)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:153)
	at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:124)
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
Caused by: java.net.BindException: Address already in use
	at sun.nio.ch.Net.bind0(Native Method)
	at sun.nio.ch.Net.bind(Net.java:344)
	at sun.nio.ch.Net.bind(Net.java:336)
	at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:199)
	at sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:74)
	at org.mortbay.jetty.nio.SelectChannelConnector.open(SelectChannelConnector.java:216)
	at org.apache.hadoop.http.HttpServer.openListener(HttpServer.java:702)
	... 34 more
2015-10-19 20:03:33,850 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:33,851 INFO  namenode.FSEditLog (FSEditLog.java:endCurrentLogSegment(992)) - Ending log segment 3
2015-10-19 20:03:33,858 INFO  namenode.FSEditLog (FSEditLog.java:printStatistics(650)) - Number of transactions: 2 Total time for transactions(ms): 1Number of transactions batched in Syncs: 0 Number of syncs: 3 SyncTimes(ms): 22 
2015-10-19 20:03:33,863 INFO  namenode.FileJournalManager (FileJournalManager.java:finalizeLogSegment(122)) - Finalizing edits file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_inprogress_0000000000000000003 -> /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000003-0000000000000000004
2015-10-19 20:03:33,865 WARN  blockmanagement.BlockManager (BlockManager.java:run(3014)) - ReplicationMonitor thread received InterruptedException.
java.lang.InterruptedException: sleep interrupted
	at java.lang.Thread.sleep(Native Method)
	at org.apache.hadoop.hdfs.server.blockmanagement.BlockManager$ReplicationMonitor.run(BlockManager.java:3012)
	at java.lang.Thread.run(Thread.java:722)
2015-10-19 20:03:33,872 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:33,873 INFO  namenode.FSNamesystem (FSNamesystem.java:stopStandbyServices(743)) - Stopping services started for standby state
2015-10-19 20:03:33,872 WARN  blockmanagement.DecommissionManager (DecommissionManager.java:run(78)) - Monitor interrupted: java.lang.InterruptedException: sleep interrupted
2015-10-19 20:03:33,874 INFO  ipc.Server (Server.java:stop(1992)) - Stopping server on 51329
2015-10-19 20:03:33,882 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(151)) - NameNode metrics system started (again)
2015-10-19 20:03:33,898 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(402)) - Only one image storage directory (dfs.namenode.name.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:33,899 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(407)) - Only one namespace edits storage directory (dfs.namenode.edits.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:33,900 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:33,901 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:33,915 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:33,916 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:33,917 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:33,917 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:33,918 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:33,919 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:33,919 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:33,920 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:33,920 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:33,921 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:33,921 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:33,922 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:33,922 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:33,925 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:33,925 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:33,926 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:33,927 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:33,937 INFO  common.Storage (Storage.java:tryLock(654)) - Lock on /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/in_use.lock acquired by nodename 5544@hadoop-VM
2015-10-19 20:03:33,940 INFO  namenode.FileJournalManager (FileJournalManager.java:recoverUnfinalizedSegments(284)) - Recovering unfinalized segments in /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current
2015-10-19 20:03:33,957 INFO  namenode.FSImage (FSImageFormat.java:load(168)) - Loading image file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/fsimage_0000000000000000000 using no compression
2015-10-19 20:03:33,958 INFO  namenode.FSImage (FSImageFormat.java:load(171)) - Number of files = 1
2015-10-19 20:03:33,961 INFO  namenode.FSImage (FSImageFormat.java:loadFilesUnderConstruction(361)) - Number of files under construction = 0
2015-10-19 20:03:33,962 INFO  namenode.FSImage (FSImageFormat.java:load(193)) - Image file of size 120 loaded in 0 seconds.
2015-10-19 20:03:33,962 INFO  namenode.FSImage (FSImage.java:loadFSImage(771)) - Loaded image for txid 0 from /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/fsimage_0000000000000000000
2015-10-19 20:03:33,963 INFO  namenode.FSImage (FSImage.java:loadEdits(712)) - Reading org.apache.hadoop.hdfs.server.namenode.RedundantEditLogInputStream@d74bf75 expecting start txid #1
2015-10-19 20:03:33,964 INFO  namenode.EditLogInputStream (RedundantEditLogInputStream.java:nextOp(177)) - Fast-forwarding stream '/home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000001-0000000000000000002' to transaction ID 1
2015-10-19 20:03:33,965 INFO  namenode.FSImage (FSEditLogLoader.java:loadFSEdits(93)) - Edits file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000001-0000000000000000002 of size 30 edits # 2 loaded in 0 seconds.
2015-10-19 20:03:33,977 INFO  namenode.FSImage (FSImage.java:loadEdits(712)) - Reading org.apache.hadoop.hdfs.server.namenode.RedundantEditLogInputStream@6bc5a139 expecting start txid #3
2015-10-19 20:03:33,980 INFO  namenode.EditLogInputStream (RedundantEditLogInputStream.java:nextOp(177)) - Fast-forwarding stream '/home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000003-0000000000000000004' to transaction ID 1
2015-10-19 20:03:33,981 INFO  namenode.FSImage (FSEditLogLoader.java:loadFSEdits(93)) - Edits file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000003-0000000000000000004 of size 30 edits # 2 loaded in 0 seconds.
2015-10-19 20:03:33,983 INFO  namenode.FSEditLog (FSEditLog.java:startLogSegment(949)) - Starting log segment at 5
2015-10-19 20:03:34,004 INFO  namenode.NameCache (NameCache.java:initialized(143)) - initialized with 0 entries 0 lookups
2015-10-19 20:03:34,004 INFO  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(424)) - Finished loading FSImage in 77 msecs
2015-10-19 20:03:34,012 INFO  ipc.Server (Server.java:run(483)) - Starting Socket Reader #1 for port 34731
2015-10-19 20:03:34,017 INFO  namenode.FSNamesystem (FSNamesystem.java:registerMBean(4651)) - Registered FSNamesystemState MBean
2015-10-19 20:03:34,028 INFO  namenode.FSNamesystem (FSNamesystem.java:getCompleteBlocksTotal(4329)) - Number of blocks under construction: 0
2015-10-19 20:03:34,029 INFO  namenode.FSNamesystem (FSNamesystem.java:initializeReplQueues(3870)) - initializing replication queues
2015-10-19 20:03:34,035 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2221)) - Total number of blocks            = 0
2015-10-19 20:03:34,036 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2222)) - Number of invalid blocks          = 0
2015-10-19 20:03:34,041 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2223)) - Number of under-replicated blocks = 0
2015-10-19 20:03:34,041 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2224)) - Number of  over-replicated blocks = 0
2015-10-19 20:03:34,042 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2226)) - Number of blocks being written    = 0
2015-10-19 20:03:34,042 INFO  hdfs.StateChange (FSNamesystem.java:initializeReplQueues(3875)) - STATE* Replication Queue initialization scan for invalid, over- and under-replicated blocks completed in 13 msec
2015-10-19 20:03:34,043 INFO  hdfs.StateChange (FSNamesystem.java:leave(3847)) - STATE* Leaving safe mode after 0 secs.
2015-10-19 20:03:34,043 INFO  hdfs.StateChange (FSNamesystem.java:leave(3857)) - STATE* Network topology has 0 racks and 0 datanodes
2015-10-19 20:03:34,043 INFO  hdfs.StateChange (FSNamesystem.java:leave(3860)) - STATE* UnderReplicatedBlocks has 0 blocks
2015-10-19 20:03:34,061 INFO  http.HttpServer (HttpServer.java:addGlobalFilter(499)) - Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
2015-10-19 20:03:34,063 INFO  http.HttpServer (HttpServer.java:addFilter(477)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context hdfs
2015-10-19 20:03:34,064 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context logs
2015-10-19 20:03:34,065 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context static
2015-10-19 20:03:34,067 INFO  http.HttpServer (WebHdfsFileSystem.java:isEnabled(142)) - dfs.webhdfs.enabled = false
2015-10-19 20:03:34,074 INFO  http.HttpServer (HttpServer.java:start(657)) - Jetty bound to port 39082
2015-10-19 20:03:34,075 INFO  mortbay.log (Slf4jLog.java:info(67)) - jetty-6.1.26
2015-10-19 20:03:34,158 INFO  mortbay.log (Slf4jLog.java:info(67)) - Started SelectChannelConnector@hadoop-VM:39082
2015-10-19 20:03:34,164 INFO  namenode.NameNode (NameNode.java:setHttpServerAddress(394)) - Web-server up at: hadoop-VM:39082
2015-10-19 20:03:34,178 INFO  ipc.Server (Server.java:run(776)) - IPC Server Responder: starting
2015-10-19 20:03:34,178 INFO  ipc.Server (Server.java:run(607)) - IPC Server listener on 34731: starting
2015-10-19 20:03:34,184 INFO  namenode.NameNode (NameNode.java:startCommonServices(491)) - NameNode up at: hadoop-VM/127.0.1.1:34731
2015-10-19 20:03:34,185 INFO  namenode.FSNamesystem (FSNamesystem.java:startActiveServices(619)) - Starting services required for active state
2015-10-19 20:03:34,186 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:34,187 INFO  namenode.FSEditLog (FSEditLog.java:endCurrentLogSegment(992)) - Ending log segment 5
2015-10-19 20:03:34,196 INFO  namenode.FSEditLog (FSEditLog.java:printStatistics(650)) - Number of transactions: 2 Total time for transactions(ms): 0Number of transactions batched in Syncs: 0 Number of syncs: 3 SyncTimes(ms): 22 
2015-10-19 20:03:34,198 INFO  namenode.FileJournalManager (FileJournalManager.java:finalizeLogSegment(122)) - Finalizing edits file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_inprogress_0000000000000000005 -> /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000005-0000000000000000006
2015-10-19 20:03:34,200 WARN  blockmanagement.BlockManager (BlockManager.java:run(3014)) - ReplicationMonitor thread received InterruptedException.
java.lang.InterruptedException: sleep interrupted
	at java.lang.Thread.sleep(Native Method)
	at org.apache.hadoop.hdfs.server.blockmanagement.BlockManager$ReplicationMonitor.run(BlockManager.java:3012)
	at java.lang.Thread.run(Thread.java:722)
2015-10-19 20:03:34,201 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:34,202 INFO  namenode.FSNamesystem (FSNamesystem.java:stopStandbyServices(743)) - Stopping services started for standby state
2015-10-19 20:03:34,202 INFO  ipc.Server (Server.java:stop(1992)) - Stopping server on 34731
2015-10-19 20:03:34,203 WARN  blockmanagement.DecommissionManager (DecommissionManager.java:run(78)) - Monitor interrupted: java.lang.InterruptedException: sleep interrupted
2015-10-19 20:03:34,208 INFO  ipc.Server (Server.java:run(781)) - Stopping IPC Server Responder
2015-10-19 20:03:34,209 INFO  ipc.Server (Server.java:run(639)) - Stopping IPC Server listener on 34731
2015-10-19 20:03:34,254 INFO  mortbay.log (Slf4jLog.java:info(67)) - Stopped SelectChannelConnector@hadoop-VM:0
2015-10-19 20:03:34,356 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:34,358 INFO  namenode.FSEditLog (FSEditLog.java:endCurrentLogSegment(992)) - Ending log segment 1
2015-10-19 20:03:34,362 INFO  namenode.FSEditLog (FSEditLog.java:printStatistics(650)) - Number of transactions: 2 Total time for transactions(ms): 15Number of transactions batched in Syncs: 0 Number of syncs: 3 SyncTimes(ms): 21 
2015-10-19 20:03:34,363 INFO  namenode.FileJournalManager (FileJournalManager.java:finalizeLogSegment(122)) - Finalizing edits file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/edits_inprogress_0000000000000000001 -> /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/edits_0000000000000000001-0000000000000000002
2015-10-19 20:03:34,364 WARN  blockmanagement.BlockManager (BlockManager.java:run(3014)) - ReplicationMonitor thread received InterruptedException.
java.lang.InterruptedException: sleep interrupted
	at java.lang.Thread.sleep(Native Method)
	at org.apache.hadoop.hdfs.server.blockmanagement.BlockManager$ReplicationMonitor.run(BlockManager.java:3012)
	at java.lang.Thread.run(Thread.java:722)
2015-10-19 20:03:34,365 WARN  blockmanagement.DecommissionManager (DecommissionManager.java:run(78)) - Monitor interrupted: java.lang.InterruptedException: sleep interrupted
2015-10-19 20:03:34,366 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:34,367 INFO  namenode.FSNamesystem (FSNamesystem.java:stopStandbyServices(743)) - Stopping services started for standby state
2015-10-19 20:03:34,368 INFO  ipc.Server (Server.java:stop(1992)) - Stopping server on 50563
2015-10-19 20:03:34,386 INFO  ipc.Server (Server.java:run(639)) - Stopping IPC Server listener on 50563
2015-10-19 20:03:34,387 INFO  ipc.Server (Server.java:run(781)) - Stopping IPC Server Responder
2015-10-19 20:03:34,427 INFO  mortbay.log (Slf4jLog.java:info(67)) - Stopped SelectChannelConnector@hadoop-VM:0
2015-10-19 20:03:34,536 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:stop(200)) - Stopping NameNode metrics system...
2015-10-19 20:03:34,540 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:stop(206)) - NameNode metrics system stopped.
2015-10-19 20:03:34,543 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:shutdown(551)) - NameNode metrics system shutdown complete.
2015-10-19 20:03:34,621 INFO  namenode.NameNode (NameNode.java:setServiceAddress(290)) - Setting ADDRESS hadoop-VM:0
Formatting using clusterid: testClusterID
2015-10-19 20:03:34,625 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:34,626 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:34,658 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:34,659 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:34,659 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:34,659 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:34,660 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:34,660 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:34,661 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:34,661 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:34,662 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:34,662 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:34,663 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:34,664 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:34,665 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:34,665 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:34,666 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:34,667 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:34,667 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:34,678 INFO  namenode.NNStorage (NNStorage.java:format(531)) - Storage directory /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1 has been successfully formatted.
2015-10-19 20:03:34,682 INFO  namenode.FSImage (FSImageFormat.java:save(504)) - Saving image file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/fsimage.ckpt_0000000000000000000 using no compression
2015-10-19 20:03:34,687 INFO  namenode.FSImage (FSImageFormat.java:save(531)) - Image file of size 120 saved in 0 seconds.
2015-10-19 20:03:34,695 INFO  namenode.NNStorageRetentionManager (NNStorageRetentionManager.java:getImageTxIdToRetain(133)) - Going to retain 1 images with txid >= 0
2015-10-19 20:03:34,698 INFO  impl.MetricsConfig (MetricsConfig.java:loadFirst(112)) - loaded properties from hadoop-metrics2.properties
2015-10-19 20:03:34,703 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:startTimer(343)) - Scheduled snapshot period at 10 second(s).
2015-10-19 20:03:34,705 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:start(183)) - NameNode metrics system started
2015-10-19 20:03:34,716 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(402)) - Only one image storage directory (dfs.namenode.name.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:34,716 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(407)) - Only one namespace edits storage directory (dfs.namenode.edits.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:34,718 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:34,719 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:34,723 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:34,725 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:34,725 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:34,726 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:34,726 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:34,726 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:34,726 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:34,727 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:34,727 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:34,728 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:34,729 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:34,729 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:34,730 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:34,731 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:34,732 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:34,732 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:34,732 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:34,740 INFO  common.Storage (Storage.java:tryLock(654)) - Lock on /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/in_use.lock acquired by nodename 5544@hadoop-VM
2015-10-19 20:03:34,743 INFO  namenode.FileJournalManager (FileJournalManager.java:recoverUnfinalizedSegments(284)) - Recovering unfinalized segments in /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current
2015-10-19 20:03:34,744 INFO  namenode.FSImage (FSImage.java:loadFSImage(628)) - No edit log streams selected.
2015-10-19 20:03:34,746 INFO  namenode.FSImage (FSImageFormat.java:load(168)) - Loading image file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/fsimage_0000000000000000000 using no compression
2015-10-19 20:03:34,747 INFO  namenode.FSImage (FSImageFormat.java:load(171)) - Number of files = 1
2015-10-19 20:03:34,747 INFO  namenode.FSImage (FSImageFormat.java:loadFilesUnderConstruction(361)) - Number of files under construction = 0
2015-10-19 20:03:34,748 INFO  namenode.FSImage (FSImageFormat.java:load(193)) - Image file of size 120 loaded in 0 seconds.
2015-10-19 20:03:34,748 INFO  namenode.FSImage (FSImage.java:loadFSImage(771)) - Loaded image for txid 0 from /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/fsimage_0000000000000000000
2015-10-19 20:03:34,749 INFO  namenode.FSEditLog (FSEditLog.java:startLogSegment(949)) - Starting log segment at 1
2015-10-19 20:03:34,766 INFO  namenode.NameCache (NameCache.java:initialized(143)) - initialized with 0 entries 0 lookups
2015-10-19 20:03:34,767 INFO  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(424)) - Finished loading FSImage in 35 msecs
2015-10-19 20:03:34,771 INFO  ipc.Server (Server.java:run(483)) - Starting Socket Reader #1 for port 39580
2015-10-19 20:03:34,779 INFO  namenode.NameNode (NameNode.java:setServiceAddress(290)) - Setting ADDRESS hadoop-VM:39580
2015-10-19 20:03:34,782 INFO  ipc.Server (Server.java:run(483)) - Starting Socket Reader #1 for port 39592
2015-10-19 20:03:34,796 INFO  namenode.FSNamesystem (FSNamesystem.java:registerMBean(4651)) - Registered FSNamesystemState MBean
2015-10-19 20:03:34,807 INFO  namenode.FSNamesystem (FSNamesystem.java:getCompleteBlocksTotal(4329)) - Number of blocks under construction: 0
2015-10-19 20:03:34,808 INFO  namenode.FSNamesystem (FSNamesystem.java:initializeReplQueues(3870)) - initializing replication queues
2015-10-19 20:03:34,812 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2221)) - Total number of blocks            = 0
2015-10-19 20:03:34,813 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2222)) - Number of invalid blocks          = 0
2015-10-19 20:03:34,813 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2223)) - Number of under-replicated blocks = 0
2015-10-19 20:03:34,813 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2224)) - Number of  over-replicated blocks = 0
2015-10-19 20:03:34,814 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2226)) - Number of blocks being written    = 0
2015-10-19 20:03:34,814 INFO  hdfs.StateChange (FSNamesystem.java:initializeReplQueues(3875)) - STATE* Replication Queue initialization scan for invalid, over- and under-replicated blocks completed in 6 msec
2015-10-19 20:03:34,814 INFO  hdfs.StateChange (FSNamesystem.java:leave(3847)) - STATE* Leaving safe mode after 0 secs.
2015-10-19 20:03:34,815 INFO  hdfs.StateChange (FSNamesystem.java:leave(3857)) - STATE* Network topology has 0 racks and 0 datanodes
2015-10-19 20:03:34,815 INFO  hdfs.StateChange (FSNamesystem.java:leave(3860)) - STATE* UnderReplicatedBlocks has 0 blocks
2015-10-19 20:03:34,825 WARN  util.MBeans (MBeans.java:register(65)) - Failed to register MBean "Hadoop:service=NameNode,name=NameNodeInfo": Instance already exists.
2015-10-19 20:03:34,841 INFO  http.HttpServer (HttpServer.java:addGlobalFilter(499)) - Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
2015-10-19 20:03:34,843 INFO  http.HttpServer (HttpServer.java:addFilter(477)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context hdfs
2015-10-19 20:03:34,844 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context logs
2015-10-19 20:03:34,844 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context static
2015-10-19 20:03:34,847 INFO  http.HttpServer (WebHdfsFileSystem.java:isEnabled(142)) - dfs.webhdfs.enabled = false
2015-10-19 20:03:34,855 INFO  http.HttpServer (HttpServer.java:start(657)) - Jetty bound to port 35792
2015-10-19 20:03:34,856 INFO  mortbay.log (Slf4jLog.java:info(67)) - jetty-6.1.26
2015-10-19 20:03:34,949 INFO  mortbay.log (Slf4jLog.java:info(67)) - Started SelectChannelConnector@hadoop-VM:35792
2015-10-19 20:03:34,960 INFO  namenode.NameNode (NameNode.java:setHttpServerAddress(394)) - Web-server up at: hadoop-VM:35792
2015-10-19 20:03:34,962 INFO  ipc.Server (Server.java:run(776)) - IPC Server Responder: starting
2015-10-19 20:03:34,963 INFO  ipc.Server (Server.java:run(607)) - IPC Server listener on 39592: starting
2015-10-19 20:03:34,982 INFO  ipc.Server (Server.java:run(776)) - IPC Server Responder: starting
2015-10-19 20:03:34,986 INFO  ipc.Server (Server.java:run(607)) - IPC Server listener on 39580: starting
2015-10-19 20:03:34,997 INFO  namenode.NameNode (NameNode.java:startCommonServices(491)) - NameNode up at: hadoop-VM/127.0.1.1:39592
2015-10-19 20:03:34,998 INFO  namenode.NameNode (NameNode.java:startCommonServices(493)) - NameNode service server is up at: hadoop-VM/127.0.1.1:39580
2015-10-19 20:03:34,998 INFO  namenode.FSNamesystem (FSNamesystem.java:startActiveServices(619)) - Starting services required for active state
Formatting using clusterid: testClusterID
2015-10-19 20:03:35,002 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:35,002 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:35,009 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:35,010 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:35,010 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:35,010 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:35,011 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:35,011 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:35,011 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:35,011 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:35,013 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:35,013 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:35,014 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:35,014 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:35,015 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:35,015 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:35,016 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:35,016 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:35,016 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:35,029 INFO  namenode.NNStorage (NNStorage.java:format(531)) - Storage directory /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2 has been successfully formatted.
2015-10-19 20:03:35,033 INFO  namenode.FSImage (FSImageFormat.java:save(504)) - Saving image file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/fsimage.ckpt_0000000000000000000 using no compression
2015-10-19 20:03:35,038 INFO  namenode.FSImage (FSImageFormat.java:save(531)) - Image file of size 120 saved in 0 seconds.
2015-10-19 20:03:35,046 INFO  namenode.NNStorageRetentionManager (NNStorageRetentionManager.java:getImageTxIdToRetain(133)) - Going to retain 1 images with txid >= 0
2015-10-19 20:03:35,047 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(151)) - NameNode metrics system started (again)
2015-10-19 20:03:35,058 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(402)) - Only one image storage directory (dfs.namenode.name.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:35,058 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(407)) - Only one namespace edits storage directory (dfs.namenode.edits.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:35,059 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:35,060 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:35,065 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:35,066 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:35,066 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:35,066 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:35,067 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:35,067 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:35,067 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:35,068 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:35,069 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:35,069 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:35,070 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:35,070 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:35,070 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:35,072 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:35,073 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:35,073 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:35,073 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:35,078 INFO  common.Storage (Storage.java:tryLock(654)) - Lock on /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/in_use.lock acquired by nodename 5544@hadoop-VM
2015-10-19 20:03:35,080 INFO  namenode.FileJournalManager (FileJournalManager.java:recoverUnfinalizedSegments(284)) - Recovering unfinalized segments in /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current
2015-10-19 20:03:35,082 INFO  namenode.FSImage (FSImage.java:loadFSImage(628)) - No edit log streams selected.
2015-10-19 20:03:35,083 INFO  namenode.FSImage (FSImageFormat.java:load(168)) - Loading image file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/fsimage_0000000000000000000 using no compression
2015-10-19 20:03:35,083 INFO  namenode.FSImage (FSImageFormat.java:load(171)) - Number of files = 1
2015-10-19 20:03:35,084 INFO  namenode.FSImage (FSImageFormat.java:loadFilesUnderConstruction(361)) - Number of files under construction = 0
2015-10-19 20:03:35,085 INFO  namenode.FSImage (FSImageFormat.java:load(193)) - Image file of size 120 loaded in 0 seconds.
2015-10-19 20:03:35,086 INFO  namenode.FSImage (FSImage.java:loadFSImage(771)) - Loaded image for txid 0 from /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/fsimage_0000000000000000000
2015-10-19 20:03:35,087 INFO  namenode.FSEditLog (FSEditLog.java:startLogSegment(949)) - Starting log segment at 1
2015-10-19 20:03:35,107 INFO  namenode.NameCache (NameCache.java:initialized(143)) - initialized with 0 entries 0 lookups
2015-10-19 20:03:35,108 INFO  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(424)) - Finished loading FSImage in 34 msecs
2015-10-19 20:03:35,110 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:35,110 INFO  namenode.FSEditLog (FSEditLog.java:endCurrentLogSegment(992)) - Ending log segment 1
2015-10-19 20:03:35,114 INFO  namenode.FSEditLog (FSEditLog.java:printStatistics(650)) - Number of transactions: 2 Total time for transactions(ms): 0Number of transactions batched in Syncs: 0 Number of syncs: 3 SyncTimes(ms): 18 
2015-10-19 20:03:35,117 INFO  namenode.FileJournalManager (FileJournalManager.java:finalizeLogSegment(122)) - Finalizing edits file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_inprogress_0000000000000000001 -> /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000001-0000000000000000002
2015-10-19 20:03:35,119 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:35,119 INFO  namenode.FSNamesystem (FSNamesystem.java:stopStandbyServices(743)) - Stopping services started for standby state
2015-10-19 20:03:35,120 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(151)) - NameNode metrics system started (again)
2015-10-19 20:03:35,131 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(402)) - Only one image storage directory (dfs.namenode.name.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:35,132 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(407)) - Only one namespace edits storage directory (dfs.namenode.edits.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:35,134 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:35,135 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:35,142 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:35,143 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:35,143 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:35,143 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:35,144 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:35,145 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:35,145 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:35,146 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:35,147 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:35,147 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:35,148 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:35,148 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:35,149 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:35,150 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:35,151 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:35,151 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:35,151 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:35,157 INFO  common.Storage (Storage.java:tryLock(654)) - Lock on /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/in_use.lock acquired by nodename 5544@hadoop-VM
2015-10-19 20:03:35,159 INFO  namenode.FileJournalManager (FileJournalManager.java:recoverUnfinalizedSegments(284)) - Recovering unfinalized segments in /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current
2015-10-19 20:03:35,163 INFO  namenode.FSImage (FSImageFormat.java:load(168)) - Loading image file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/fsimage_0000000000000000000 using no compression
2015-10-19 20:03:35,163 INFO  namenode.FSImage (FSImageFormat.java:load(171)) - Number of files = 1
2015-10-19 20:03:35,164 INFO  namenode.FSImage (FSImageFormat.java:loadFilesUnderConstruction(361)) - Number of files under construction = 0
2015-10-19 20:03:35,164 INFO  namenode.FSImage (FSImageFormat.java:load(193)) - Image file of size 120 loaded in 0 seconds.
2015-10-19 20:03:35,165 INFO  namenode.FSImage (FSImage.java:loadFSImage(771)) - Loaded image for txid 0 from /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/fsimage_0000000000000000000
2015-10-19 20:03:35,165 INFO  namenode.FSImage (FSImage.java:loadEdits(712)) - Reading org.apache.hadoop.hdfs.server.namenode.RedundantEditLogInputStream@3ffbe014 expecting start txid #1
2015-10-19 20:03:35,165 INFO  namenode.EditLogInputStream (RedundantEditLogInputStream.java:nextOp(177)) - Fast-forwarding stream '/home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000001-0000000000000000002' to transaction ID 1
2015-10-19 20:03:35,166 INFO  namenode.FSImage (FSEditLogLoader.java:loadFSEdits(93)) - Edits file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000001-0000000000000000002 of size 30 edits # 2 loaded in 0 seconds.
2015-10-19 20:03:35,169 INFO  namenode.FSEditLog (FSEditLog.java:startLogSegment(949)) - Starting log segment at 3
2015-10-19 20:03:35,405 INFO  namenode.NameCache (NameCache.java:initialized(143)) - initialized with 0 entries 0 lookups
2015-10-19 20:03:35,406 INFO  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(424)) - Finished loading FSImage in 254 msecs
2015-10-19 20:03:35,409 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:35,409 INFO  namenode.FSEditLog (FSEditLog.java:endCurrentLogSegment(992)) - Ending log segment 3
2015-10-19 20:03:35,413 INFO  namenode.FSEditLog (FSEditLog.java:printStatistics(650)) - Number of transactions: 2 Total time for transactions(ms): 0Number of transactions batched in Syncs: 0 Number of syncs: 3 SyncTimes(ms): 19 
2015-10-19 20:03:35,414 INFO  namenode.FileJournalManager (FileJournalManager.java:finalizeLogSegment(122)) - Finalizing edits file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_inprogress_0000000000000000003 -> /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000003-0000000000000000004
2015-10-19 20:03:35,415 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:35,415 INFO  namenode.FSNamesystem (FSNamesystem.java:stopStandbyServices(743)) - Stopping services started for standby state
2015-10-19 20:03:35,417 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(151)) - NameNode metrics system started (again)
2015-10-19 20:03:35,431 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(402)) - Only one image storage directory (dfs.namenode.name.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:35,432 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(407)) - Only one namespace edits storage directory (dfs.namenode.edits.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:35,434 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:35,434 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:35,437 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:35,438 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:35,438 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:35,438 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:35,439 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:35,439 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:35,439 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:35,440 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:35,440 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:35,441 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:35,441 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:35,442 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:35,443 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:35,443 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:35,444 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:35,445 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:35,445 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:35,452 INFO  common.Storage (Storage.java:tryLock(654)) - Lock on /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/in_use.lock acquired by nodename 5544@hadoop-VM
2015-10-19 20:03:35,454 INFO  namenode.FileJournalManager (FileJournalManager.java:recoverUnfinalizedSegments(284)) - Recovering unfinalized segments in /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current
2015-10-19 20:03:35,458 INFO  namenode.FSImage (FSImageFormat.java:load(168)) - Loading image file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/fsimage_0000000000000000000 using no compression
2015-10-19 20:03:35,458 INFO  namenode.FSImage (FSImageFormat.java:load(171)) - Number of files = 1
2015-10-19 20:03:35,459 INFO  namenode.FSImage (FSImageFormat.java:loadFilesUnderConstruction(361)) - Number of files under construction = 0
2015-10-19 20:03:35,460 INFO  namenode.FSImage (FSImageFormat.java:load(193)) - Image file of size 120 loaded in 0 seconds.
2015-10-19 20:03:35,460 INFO  namenode.FSImage (FSImage.java:loadFSImage(771)) - Loaded image for txid 0 from /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/fsimage_0000000000000000000
2015-10-19 20:03:35,460 INFO  namenode.FSImage (FSImage.java:loadEdits(712)) - Reading org.apache.hadoop.hdfs.server.namenode.RedundantEditLogInputStream@6100bf59 expecting start txid #1
2015-10-19 20:03:35,460 INFO  namenode.EditLogInputStream (RedundantEditLogInputStream.java:nextOp(177)) - Fast-forwarding stream '/home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000001-0000000000000000002' to transaction ID 1
2015-10-19 20:03:35,461 INFO  namenode.FSImage (FSEditLogLoader.java:loadFSEdits(93)) - Edits file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000001-0000000000000000002 of size 30 edits # 2 loaded in 0 seconds.
2015-10-19 20:03:35,462 INFO  namenode.FSImage (FSImage.java:loadEdits(712)) - Reading org.apache.hadoop.hdfs.server.namenode.RedundantEditLogInputStream@78129dcf expecting start txid #3
2015-10-19 20:03:35,462 INFO  namenode.EditLogInputStream (RedundantEditLogInputStream.java:nextOp(177)) - Fast-forwarding stream '/home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000003-0000000000000000004' to transaction ID 1
2015-10-19 20:03:35,463 INFO  namenode.FSImage (FSEditLogLoader.java:loadFSEdits(93)) - Edits file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000003-0000000000000000004 of size 30 edits # 2 loaded in 0 seconds.
2015-10-19 20:03:35,465 INFO  namenode.FSEditLog (FSEditLog.java:startLogSegment(949)) - Starting log segment at 5
2015-10-19 20:03:35,487 INFO  namenode.NameCache (NameCache.java:initialized(143)) - initialized with 0 entries 0 lookups
2015-10-19 20:03:35,488 INFO  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(424)) - Finished loading FSImage in 42 msecs
2015-10-19 20:03:35,490 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:35,491 INFO  namenode.FSEditLog (FSEditLog.java:endCurrentLogSegment(992)) - Ending log segment 5
2015-10-19 20:03:35,497 INFO  namenode.FSEditLog (FSEditLog.java:printStatistics(650)) - Number of transactions: 2 Total time for transactions(ms): 2Number of transactions batched in Syncs: 0 Number of syncs: 3 SyncTimes(ms): 17 
2015-10-19 20:03:35,498 INFO  namenode.FileJournalManager (FileJournalManager.java:finalizeLogSegment(122)) - Finalizing edits file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_inprogress_0000000000000000005 -> /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000005-0000000000000000006
2015-10-19 20:03:35,500 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:35,500 INFO  namenode.FSNamesystem (FSNamesystem.java:stopStandbyServices(743)) - Stopping services started for standby state
2015-10-19 20:03:35,501 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(151)) - NameNode metrics system started (again)
2015-10-19 20:03:35,513 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(402)) - Only one image storage directory (dfs.namenode.name.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:35,513 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(407)) - Only one namespace edits storage directory (dfs.namenode.edits.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:35,514 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:35,515 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:35,518 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:35,519 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:35,520 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:35,520 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:35,520 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:35,521 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:35,521 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:35,521 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:35,522 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:35,523 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:35,523 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:35,524 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:35,525 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:35,525 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:35,526 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:35,526 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:35,526 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:35,532 INFO  common.Storage (Storage.java:tryLock(654)) - Lock on /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/in_use.lock acquired by nodename 5544@hadoop-VM
2015-10-19 20:03:35,535 INFO  namenode.FileJournalManager (FileJournalManager.java:recoverUnfinalizedSegments(284)) - Recovering unfinalized segments in /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current
2015-10-19 20:03:35,541 INFO  namenode.FSImage (FSImageFormat.java:load(168)) - Loading image file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/fsimage_0000000000000000000 using no compression
2015-10-19 20:03:35,541 INFO  namenode.FSImage (FSImageFormat.java:load(171)) - Number of files = 1
2015-10-19 20:03:35,542 INFO  namenode.FSImage (FSImageFormat.java:loadFilesUnderConstruction(361)) - Number of files under construction = 0
2015-10-19 20:03:35,542 INFO  namenode.FSImage (FSImageFormat.java:load(193)) - Image file of size 120 loaded in 0 seconds.
2015-10-19 20:03:35,542 INFO  namenode.FSImage (FSImage.java:loadFSImage(771)) - Loaded image for txid 0 from /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/fsimage_0000000000000000000
2015-10-19 20:03:35,543 INFO  namenode.FSImage (FSImage.java:loadEdits(712)) - Reading org.apache.hadoop.hdfs.server.namenode.RedundantEditLogInputStream@42e0dd34 expecting start txid #1
2015-10-19 20:03:35,543 INFO  namenode.EditLogInputStream (RedundantEditLogInputStream.java:nextOp(177)) - Fast-forwarding stream '/home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000001-0000000000000000002' to transaction ID 1
2015-10-19 20:03:35,544 INFO  namenode.FSImage (FSEditLogLoader.java:loadFSEdits(93)) - Edits file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000001-0000000000000000002 of size 30 edits # 2 loaded in 0 seconds.
2015-10-19 20:03:35,544 INFO  namenode.FSImage (FSImage.java:loadEdits(712)) - Reading org.apache.hadoop.hdfs.server.namenode.RedundantEditLogInputStream@38daa339 expecting start txid #3
2015-10-19 20:03:35,544 INFO  namenode.EditLogInputStream (RedundantEditLogInputStream.java:nextOp(177)) - Fast-forwarding stream '/home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000003-0000000000000000004' to transaction ID 1
2015-10-19 20:03:35,546 INFO  namenode.FSImage (FSEditLogLoader.java:loadFSEdits(93)) - Edits file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000003-0000000000000000004 of size 30 edits # 2 loaded in 0 seconds.
2015-10-19 20:03:35,546 INFO  namenode.FSImage (FSImage.java:loadEdits(712)) - Reading org.apache.hadoop.hdfs.server.namenode.RedundantEditLogInputStream@1a121058 expecting start txid #5
2015-10-19 20:03:35,546 INFO  namenode.EditLogInputStream (RedundantEditLogInputStream.java:nextOp(177)) - Fast-forwarding stream '/home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000005-0000000000000000006' to transaction ID 1
2015-10-19 20:03:35,547 INFO  namenode.FSImage (FSEditLogLoader.java:loadFSEdits(93)) - Edits file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000005-0000000000000000006 of size 30 edits # 2 loaded in 0 seconds.
2015-10-19 20:03:35,550 INFO  namenode.FSEditLog (FSEditLog.java:startLogSegment(949)) - Starting log segment at 7
2015-10-19 20:03:35,573 INFO  namenode.NameCache (NameCache.java:initialized(143)) - initialized with 0 entries 0 lookups
2015-10-19 20:03:35,573 INFO  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(424)) - Finished loading FSImage in 46 msecs
2015-10-19 20:03:35,577 INFO  ipc.Server (Server.java:run(483)) - Starting Socket Reader #1 for port 33604
2015-10-19 20:03:35,583 INFO  namenode.NameNode (NameNode.java:setServiceAddress(290)) - Setting ADDRESS hadoop-VM:33604
2015-10-19 20:03:35,592 INFO  namenode.FSNamesystem (FSNamesystem.java:registerMBean(4651)) - Registered FSNamesystemState MBean
2015-10-19 20:03:35,593 INFO  ipc.Server (Server.java:run(483)) - Starting Socket Reader #1 for port 40292
2015-10-19 20:03:35,604 INFO  namenode.FSNamesystem (FSNamesystem.java:getCompleteBlocksTotal(4329)) - Number of blocks under construction: 0
2015-10-19 20:03:35,605 INFO  namenode.FSNamesystem (FSNamesystem.java:initializeReplQueues(3870)) - initializing replication queues
2015-10-19 20:03:35,608 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2221)) - Total number of blocks            = 0
2015-10-19 20:03:35,609 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2222)) - Number of invalid blocks          = 0
2015-10-19 20:03:35,609 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2223)) - Number of under-replicated blocks = 0
2015-10-19 20:03:35,610 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2224)) - Number of  over-replicated blocks = 0
2015-10-19 20:03:35,610 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2226)) - Number of blocks being written    = 0
2015-10-19 20:03:35,612 INFO  hdfs.StateChange (FSNamesystem.java:initializeReplQueues(3875)) - STATE* Replication Queue initialization scan for invalid, over- and under-replicated blocks completed in 7 msec
2015-10-19 20:03:35,613 INFO  hdfs.StateChange (FSNamesystem.java:leave(3847)) - STATE* Leaving safe mode after 0 secs.
2015-10-19 20:03:35,613 INFO  hdfs.StateChange (FSNamesystem.java:leave(3857)) - STATE* Network topology has 0 racks and 0 datanodes
2015-10-19 20:03:35,614 INFO  hdfs.StateChange (FSNamesystem.java:leave(3860)) - STATE* UnderReplicatedBlocks has 0 blocks
2015-10-19 20:03:35,616 WARN  util.MBeans (MBeans.java:register(65)) - Failed to register MBean "Hadoop:service=NameNode,name=NameNodeInfo-1": Instance already exists.
2015-10-19 20:03:35,638 INFO  http.HttpServer (HttpServer.java:addGlobalFilter(499)) - Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
2015-10-19 20:03:35,641 INFO  http.HttpServer (HttpServer.java:addFilter(477)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context hdfs
2015-10-19 20:03:35,641 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context static
2015-10-19 20:03:35,642 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context logs
2015-10-19 20:03:35,644 INFO  http.HttpServer (WebHdfsFileSystem.java:isEnabled(142)) - dfs.webhdfs.enabled = false
2015-10-19 20:03:35,649 INFO  http.HttpServer (HttpServer.java:start(657)) - Jetty bound to port 55994
2015-10-19 20:03:35,649 INFO  mortbay.log (Slf4jLog.java:info(67)) - jetty-6.1.26
2015-10-19 20:03:35,695 INFO  mortbay.log (Slf4jLog.java:info(67)) - Started SelectChannelConnector@hadoop-VM:55994
2015-10-19 20:03:35,708 INFO  namenode.NameNode (NameNode.java:setHttpServerAddress(394)) - Web-server up at: hadoop-VM:55994
2015-10-19 20:03:35,709 INFO  ipc.Server (Server.java:run(776)) - IPC Server Responder: starting
2015-10-19 20:03:35,716 INFO  ipc.Server (Server.java:run(607)) - IPC Server listener on 40292: starting
2015-10-19 20:03:35,749 INFO  ipc.Server (Server.java:run(776)) - IPC Server Responder: starting
2015-10-19 20:03:35,750 INFO  ipc.Server (Server.java:run(607)) - IPC Server listener on 33604: starting
2015-10-19 20:03:35,765 INFO  namenode.NameNode (NameNode.java:startCommonServices(491)) - NameNode up at: hadoop-VM/127.0.1.1:40292
2015-10-19 20:03:35,766 INFO  namenode.NameNode (NameNode.java:startCommonServices(493)) - NameNode service server is up at: hadoop-VM/127.0.1.1:33604
2015-10-19 20:03:35,766 INFO  namenode.FSNamesystem (FSNamesystem.java:startActiveServices(619)) - Starting services required for active state
2015-10-19 20:03:35,767 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:35,767 INFO  namenode.FSEditLog (FSEditLog.java:endCurrentLogSegment(992)) - Ending log segment 7
2015-10-19 20:03:35,773 INFO  namenode.FSEditLog (FSEditLog.java:printStatistics(650)) - Number of transactions: 2 Total time for transactions(ms): 0Number of transactions batched in Syncs: 0 Number of syncs: 3 SyncTimes(ms): 21 
2015-10-19 20:03:35,776 INFO  namenode.FileJournalManager (FileJournalManager.java:finalizeLogSegment(122)) - Finalizing edits file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_inprogress_0000000000000000007 -> /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name2/current/edits_0000000000000000007-0000000000000000008
2015-10-19 20:03:35,777 WARN  blockmanagement.BlockManager (BlockManager.java:run(3014)) - ReplicationMonitor thread received InterruptedException.
java.lang.InterruptedException: sleep interrupted
	at java.lang.Thread.sleep(Native Method)
	at org.apache.hadoop.hdfs.server.blockmanagement.BlockManager$ReplicationMonitor.run(BlockManager.java:3012)
	at java.lang.Thread.run(Thread.java:722)
2015-10-19 20:03:35,779 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:35,779 WARN  blockmanagement.DecommissionManager (DecommissionManager.java:run(78)) - Monitor interrupted: java.lang.InterruptedException: sleep interrupted
2015-10-19 20:03:35,779 INFO  namenode.FSNamesystem (FSNamesystem.java:stopStandbyServices(743)) - Stopping services started for standby state
2015-10-19 20:03:35,780 INFO  ipc.Server (Server.java:stop(1992)) - Stopping server on 40292
2015-10-19 20:03:35,784 INFO  ipc.Server (Server.java:stop(1992)) - Stopping server on 33604
2015-10-19 20:03:35,784 INFO  ipc.Server (Server.java:run(781)) - Stopping IPC Server Responder
2015-10-19 20:03:35,785 INFO  ipc.Server (Server.java:run(639)) - Stopping IPC Server listener on 40292
2015-10-19 20:03:35,791 INFO  ipc.Server (Server.java:run(639)) - Stopping IPC Server listener on 33604
2015-10-19 20:03:35,791 INFO  ipc.Server (Server.java:run(781)) - Stopping IPC Server Responder
2015-10-19 20:03:35,824 INFO  mortbay.log (Slf4jLog.java:info(67)) - Stopped SelectChannelConnector@hadoop-VM:0
2015-10-19 20:03:35,837 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:35,838 INFO  namenode.FSEditLog (FSEditLog.java:endCurrentLogSegment(992)) - Ending log segment 1
2015-10-19 20:03:35,844 INFO  namenode.FSEditLog (FSEditLog.java:printStatistics(650)) - Number of transactions: 2 Total time for transactions(ms): 0Number of transactions batched in Syncs: 0 Number of syncs: 3 SyncTimes(ms): 18 
2015-10-19 20:03:35,845 INFO  namenode.FileJournalManager (FileJournalManager.java:finalizeLogSegment(122)) - Finalizing edits file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/edits_inprogress_0000000000000000001 -> /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/edits_0000000000000000001-0000000000000000002
2015-10-19 20:03:35,847 WARN  blockmanagement.BlockManager (BlockManager.java:run(3014)) - ReplicationMonitor thread received InterruptedException.
java.lang.InterruptedException: sleep interrupted
	at java.lang.Thread.sleep(Native Method)
	at org.apache.hadoop.hdfs.server.blockmanagement.BlockManager$ReplicationMonitor.run(BlockManager.java:3012)
	at java.lang.Thread.run(Thread.java:722)
2015-10-19 20:03:35,848 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:35,849 INFO  namenode.FSNamesystem (FSNamesystem.java:stopStandbyServices(743)) - Stopping services started for standby state
2015-10-19 20:03:35,849 WARN  blockmanagement.DecommissionManager (DecommissionManager.java:run(78)) - Monitor interrupted: java.lang.InterruptedException: sleep interrupted
2015-10-19 20:03:35,850 INFO  ipc.Server (Server.java:stop(1992)) - Stopping server on 39592
2015-10-19 20:03:35,878 INFO  ipc.Server (Server.java:stop(1992)) - Stopping server on 39580
2015-10-19 20:03:35,878 INFO  ipc.Server (Server.java:run(781)) - Stopping IPC Server Responder
2015-10-19 20:03:35,880 INFO  ipc.Server (Server.java:run(639)) - Stopping IPC Server listener on 39592
2015-10-19 20:03:35,889 INFO  ipc.Server (Server.java:run(639)) - Stopping IPC Server listener on 39580
2015-10-19 20:03:35,890 INFO  ipc.Server (Server.java:run(781)) - Stopping IPC Server Responder
2015-10-19 20:03:35,926 INFO  mortbay.log (Slf4jLog.java:info(67)) - Stopped SelectChannelConnector@hadoop-VM:0
2015-10-19 20:03:36,028 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:stop(200)) - Stopping NameNode metrics system...
2015-10-19 20:03:36,033 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:stop(206)) - NameNode metrics system stopped.
2015-10-19 20:03:36,033 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:shutdown(551)) - NameNode metrics system shutdown complete.
Formatting using clusterid: testClusterID
2015-10-19 20:03:36,105 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:36,106 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:36,109 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:36,110 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:36,110 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:36,110 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:36,111 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:36,111 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:36,111 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:36,112 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:36,112 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:36,112 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:36,113 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:36,114 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:36,115 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:36,116 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:36,116 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:36,116 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:36,116 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:36,131 INFO  namenode.NNStorage (NNStorage.java:format(531)) - Storage directory /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1 has been successfully formatted.
2015-10-19 20:03:36,134 INFO  namenode.FSImage (FSImageFormat.java:save(504)) - Saving image file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/fsimage.ckpt_0000000000000000000 using no compression
2015-10-19 20:03:36,142 INFO  namenode.FSImage (FSImageFormat.java:save(531)) - Image file of size 120 saved in 0 seconds.
2015-10-19 20:03:36,151 INFO  namenode.NNStorageRetentionManager (NNStorageRetentionManager.java:getImageTxIdToRetain(133)) - Going to retain 1 images with txid >= 0
2015-10-19 20:03:36,155 INFO  impl.MetricsConfig (MetricsConfig.java:loadFirst(112)) - loaded properties from hadoop-metrics2.properties
2015-10-19 20:03:36,159 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:startTimer(343)) - Scheduled snapshot period at 10 second(s).
2015-10-19 20:03:36,160 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:start(183)) - NameNode metrics system started
2015-10-19 20:03:36,171 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(402)) - Only one image storage directory (dfs.namenode.name.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:36,171 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(407)) - Only one namespace edits storage directory (dfs.namenode.edits.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:36,173 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:36,173 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:36,176 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:36,177 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:36,177 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:36,177 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:36,178 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:36,178 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:36,179 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:36,179 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:36,180 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:36,181 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:36,181 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:36,181 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:36,182 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:36,183 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:36,183 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:36,183 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:36,184 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:36,188 INFO  common.Storage (Storage.java:tryLock(654)) - Lock on /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/in_use.lock acquired by nodename 5544@hadoop-VM
2015-10-19 20:03:36,190 INFO  namenode.FileJournalManager (FileJournalManager.java:recoverUnfinalizedSegments(284)) - Recovering unfinalized segments in /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current
2015-10-19 20:03:36,193 INFO  namenode.FSImage (FSImage.java:loadFSImage(628)) - No edit log streams selected.
2015-10-19 20:03:36,194 INFO  namenode.FSImage (FSImageFormat.java:load(168)) - Loading image file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/fsimage_0000000000000000000 using no compression
2015-10-19 20:03:36,195 INFO  namenode.FSImage (FSImageFormat.java:load(171)) - Number of files = 1
2015-10-19 20:03:36,195 INFO  namenode.FSImage (FSImageFormat.java:loadFilesUnderConstruction(361)) - Number of files under construction = 0
2015-10-19 20:03:36,196 INFO  namenode.FSImage (FSImageFormat.java:load(193)) - Image file of size 120 loaded in 0 seconds.
2015-10-19 20:03:36,196 INFO  namenode.FSImage (FSImage.java:loadFSImage(771)) - Loaded image for txid 0 from /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/fsimage_0000000000000000000
2015-10-19 20:03:36,198 INFO  namenode.FSEditLog (FSEditLog.java:startLogSegment(949)) - Starting log segment at 1
2015-10-19 20:03:36,216 INFO  namenode.NameCache (NameCache.java:initialized(143)) - initialized with 0 entries 0 lookups
2015-10-19 20:03:36,217 INFO  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(424)) - Finished loading FSImage in 33 msecs
2015-10-19 20:03:36,224 INFO  ipc.Server (Server.java:run(483)) - Starting Socket Reader #1 for port 53151
2015-10-19 20:03:36,226 INFO  namenode.FSNamesystem (FSNamesystem.java:registerMBean(4651)) - Registered FSNamesystemState MBean
2015-10-19 20:03:36,239 INFO  namenode.FSNamesystem (FSNamesystem.java:getCompleteBlocksTotal(4329)) - Number of blocks under construction: 0
2015-10-19 20:03:36,239 INFO  namenode.FSNamesystem (FSNamesystem.java:initializeReplQueues(3870)) - initializing replication queues
2015-10-19 20:03:36,243 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2221)) - Total number of blocks            = 0
2015-10-19 20:03:36,245 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2222)) - Number of invalid blocks          = 0
2015-10-19 20:03:36,245 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2223)) - Number of under-replicated blocks = 0
2015-10-19 20:03:36,247 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2224)) - Number of  over-replicated blocks = 0
2015-10-19 20:03:36,248 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2226)) - Number of blocks being written    = 0
2015-10-19 20:03:36,248 INFO  hdfs.StateChange (FSNamesystem.java:initializeReplQueues(3875)) - STATE* Replication Queue initialization scan for invalid, over- and under-replicated blocks completed in 8 msec
2015-10-19 20:03:36,249 INFO  hdfs.StateChange (FSNamesystem.java:leave(3847)) - STATE* Leaving safe mode after 0 secs.
2015-10-19 20:03:36,249 INFO  hdfs.StateChange (FSNamesystem.java:leave(3857)) - STATE* Network topology has 0 racks and 0 datanodes
2015-10-19 20:03:36,250 INFO  hdfs.StateChange (FSNamesystem.java:leave(3860)) - STATE* UnderReplicatedBlocks has 0 blocks
2015-10-19 20:03:36,254 WARN  util.MBeans (MBeans.java:register(65)) - Failed to register MBean "Hadoop:service=NameNode,name=NameNodeInfo": Instance already exists.
2015-10-19 20:03:36,272 INFO  http.HttpServer (HttpServer.java:addGlobalFilter(499)) - Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
2015-10-19 20:03:36,273 INFO  http.HttpServer (HttpServer.java:addFilter(477)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context hdfs
2015-10-19 20:03:36,274 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context logs
2015-10-19 20:03:36,275 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context static
2015-10-19 20:03:36,277 INFO  http.HttpServer (WebHdfsFileSystem.java:isEnabled(142)) - dfs.webhdfs.enabled = false
2015-10-19 20:03:36,282 INFO  http.HttpServer (HttpServer.java:start(657)) - Jetty bound to port 53476
2015-10-19 20:03:36,283 INFO  mortbay.log (Slf4jLog.java:info(67)) - jetty-6.1.26
2015-10-19 20:03:36,333 INFO  mortbay.log (Slf4jLog.java:info(67)) - Started SelectChannelConnector@hadoop-VM:53476
2015-10-19 20:03:36,335 INFO  namenode.NameNode (NameNode.java:setHttpServerAddress(394)) - Web-server up at: hadoop-VM:53476
2015-10-19 20:03:36,338 INFO  ipc.Server (Server.java:run(607)) - IPC Server listener on 53151: starting
2015-10-19 20:03:36,348 INFO  ipc.Server (Server.java:run(776)) - IPC Server Responder: starting
2015-10-19 20:03:36,349 INFO  namenode.NameNode (NameNode.java:startCommonServices(491)) - NameNode up at: hadoop-VM/127.0.1.1:53151
2015-10-19 20:03:36,351 INFO  namenode.FSNamesystem (FSNamesystem.java:startActiveServices(619)) - Starting services required for active state
2015-10-19 20:03:36,402 WARN  common.Util (Util.java:stringAsURI(56)) - Path /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/data should be specified as a URI in configuration files. Please update hdfs configuration.
2015-10-19 20:03:36,510 WARN  util.NativeCodeLoader (NativeCodeLoader.java:(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2015-10-19 20:03:36,532 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(151)) - DataNode metrics system started (again)
2015-10-19 20:03:36,533 INFO  datanode.DataNode (DataNode.java:(313)) - Configured hostname is hadoop-VM
2015-10-19 20:03:36,552 WARN  common.Util (Util.java:stringAsURI(56)) - Path /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/data should be specified as a URI in configuration files. Please update hdfs configuration.
2015-10-19 20:03:36,580 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(151)) - DataNode metrics system started (again)
2015-10-19 20:03:36,580 INFO  datanode.DataNode (DataNode.java:(313)) - Configured hostname is hadoop-VM
2015-10-19 20:03:36,583 INFO  datanode.DataNode (DataNode.java:initDataXceiver(535)) - Opened streaming server at /127.0.1.1:36702
2015-10-19 20:03:36,590 INFO  datanode.DataNode (DataXceiverServer.java:(77)) - Balancing bandwith is 1048576 bytes/s
2015-10-19 20:03:36,592 INFO  http.HttpServer (HttpServer.java:addGlobalFilter(499)) - Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
2015-10-19 20:03:36,593 INFO  http.HttpServer (HttpServer.java:addFilter(477)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context datanode
2015-10-19 20:03:36,594 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context static
2015-10-19 20:03:36,594 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context logs
2015-10-19 20:03:36,596 INFO  datanode.DataNode (DataNode.java:startInfoServer(365)) - Opened info server at hadoop-VM:53476
2015-10-19 20:03:36,603 INFO  datanode.DataNode (WebHdfsFileSystem.java:isEnabled(142)) - dfs.webhdfs.enabled = false
2015-10-19 20:03:36,604 INFO  http.HttpServer (HttpServer.java:start(660)) - HttpServer.start() threw a non Bind IOException
java.net.BindException: Port in use: hadoop-VM:53476
	at org.apache.hadoop.http.HttpServer.openListener(HttpServer.java:706)
	at org.apache.hadoop.http.HttpServer.start(HttpServer.java:656)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.startInfoServer(DataNode.java:393)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.startDataNode(DataNode.java:674)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.(DataNode.java:314)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.makeInstance(DataNode.java:1643)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1576)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.createDataNode(DataNode.java:1599)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.createDataNode(DataNode.java:1590)
	at org.apache.hadoop.hdfs.TestHDFSServerPorts.canStartDataNode(TestHDFSServerPorts.java:204)
	at org.apache.hadoop.hdfs.TestHDFSServerPorts.testDataNodePorts(TestHDFSServerPorts.java:324)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
	at org.junit.runners.BlockJUnit4ClassRunner.runNotIgnored(BlockJUnit4ClassRunner.java:79)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:71)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:49)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
	at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:264)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:153)
	at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:124)
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
Caused by: java.net.BindException: Address already in use
	at sun.nio.ch.Net.bind0(Native Method)
	at sun.nio.ch.Net.bind(Net.java:344)
	at sun.nio.ch.Net.bind(Net.java:336)
	at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:199)
	at sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:74)
	at org.mortbay.jetty.nio.SelectChannelConnector.open(SelectChannelConnector.java:216)
	at org.apache.hadoop.http.HttpServer.openListener(HttpServer.java:702)
	... 33 more
2015-10-19 20:03:36,606 INFO  datanode.DataNode (DataNode.java:shutdown(1116)) - Waiting for threadgroup to exit, active threads is 0
2015-10-19 20:03:36,608 WARN  common.Util (Util.java:stringAsURI(56)) - Path /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/data should be specified as a URI in configuration files. Please update hdfs configuration.
2015-10-19 20:03:36,630 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(151)) - DataNode metrics system started (again)
2015-10-19 20:03:36,630 INFO  datanode.DataNode (DataNode.java:(313)) - Configured hostname is hadoop-VM
2015-10-19 20:03:36,633 INFO  datanode.DataNode (DataNode.java:initDataXceiver(535)) - Opened streaming server at /127.0.1.1:41964
2015-10-19 20:03:36,633 INFO  datanode.DataNode (DataXceiverServer.java:(77)) - Balancing bandwith is 1048576 bytes/s
2015-10-19 20:03:36,635 INFO  http.HttpServer (HttpServer.java:addGlobalFilter(499)) - Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
2015-10-19 20:03:36,637 INFO  http.HttpServer (HttpServer.java:addFilter(477)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context datanode
2015-10-19 20:03:36,638 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context static
2015-10-19 20:03:36,638 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context logs
2015-10-19 20:03:36,641 INFO  datanode.DataNode (DataNode.java:startInfoServer(365)) - Opened info server at hadoop-VM:0
2015-10-19 20:03:36,642 INFO  datanode.DataNode (WebHdfsFileSystem.java:isEnabled(142)) - dfs.webhdfs.enabled = false
2015-10-19 20:03:36,643 INFO  http.HttpServer (HttpServer.java:start(657)) - Jetty bound to port 46834
2015-10-19 20:03:36,644 INFO  mortbay.log (Slf4jLog.java:info(67)) - jetty-6.1.26
2015-10-19 20:03:36,735 INFO  mortbay.log (Slf4jLog.java:info(67)) - Started SelectChannelConnector@hadoop-VM:46834
2015-10-19 20:03:36,761 INFO  ipc.Server (Server.java:run(483)) - Starting Socket Reader #1 for port 36436
2015-10-19 20:03:36,778 INFO  datanode.DataNode (DataNode.java:initIpcServer(431)) - Opened IPC server at /127.0.1.1:36436
2015-10-19 20:03:36,797 INFO  datanode.DataNode (BlockPoolManager.java:refreshNamenodes(148)) - Refresh request received for nameservices: null
2015-10-19 20:03:36,805 INFO  datanode.DataNode (BlockPoolManager.java:doRefreshNamenodes(193)) - Starting BPOfferServices for nameservices: 
2015-10-19 20:03:36,824 WARN  common.Util (Util.java:stringAsURI(56)) - Path /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/data should be specified as a URI in configuration files. Please update hdfs configuration.
2015-10-19 20:03:36,843 INFO  datanode.DataNode (BPServiceActor.java:run(655)) - Block pool  (storage id unknown) service to hadoop-VM/127.0.1.1:53151 starting to offer service
2015-10-19 20:03:36,848 INFO  ipc.Server (Server.java:run(776)) - IPC Server Responder: starting
2015-10-19 20:03:36,849 INFO  ipc.Server (Server.java:run(607)) - IPC Server listener on 36436: starting
2015-10-19 20:03:36,890 INFO  mortbay.log (Slf4jLog.java:info(67)) - Stopped SelectChannelConnector@hadoop-VM:0
2015-10-19 20:03:36,900 INFO  ipc.Server (Server.java:stop(1992)) - Stopping server on 36436
2015-10-19 20:03:36,905 INFO  ipc.Server (Server.java:run(639)) - Stopping IPC Server listener on 36436
2015-10-19 20:03:36,906 INFO  ipc.Server (Server.java:run(781)) - Stopping IPC Server Responder
2015-10-19 20:03:36,908 INFO  datanode.DataNode (DataNode.java:shutdown(1116)) - Waiting for threadgroup to exit, active threads is 1
2015-10-19 20:03:36,911 INFO  datanode.DataNode (DataNode.java:shutdown(1116)) - Waiting for threadgroup to exit, active threads is 0
2015-10-19 20:03:37,019 FATAL datanode.DataNode (BPServiceActor.java:run(665)) - Initialization failed for block pool Block pool  (storage id unknown) service to hadoop-VM/127.0.1.1:53151
java.io.IOException: DN shut down before block pool connected
	at org.apache.hadoop.hdfs.server.datanode.BPServiceActor.retrieveNamespaceInfo(BPServiceActor.java:175)
	at org.apache.hadoop.hdfs.server.datanode.BPServiceActor.connectToNNAndHandshake(BPServiceActor.java:213)
	at org.apache.hadoop.hdfs.server.datanode.BPServiceActor.run(BPServiceActor.java:661)
	at java.lang.Thread.run(Thread.java:722)
2015-10-19 20:03:37,021 WARN  datanode.DataNode (BPServiceActor.java:run(683)) - Ending block pool service for: Block pool  (storage id unknown) service to hadoop-VM/127.0.1.1:53151
2015-10-19 20:03:37,023 WARN  datanode.DataNode (BPOfferService.java:getBlockPoolId(154)) - Block pool ID needed, but service not yet registered with NN
java.lang.Exception: trace
	at org.apache.hadoop.hdfs.server.datanode.BPOfferService.getBlockPoolId(BPOfferService.java:154)
	at org.apache.hadoop.hdfs.server.datanode.BlockPoolManager.remove(BlockPoolManager.java:91)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.shutdownBlockPool(DataNode.java:776)
	at org.apache.hadoop.hdfs.server.datanode.BPOfferService.shutdownActor(BPOfferService.java:376)
	at org.apache.hadoop.hdfs.server.datanode.BPServiceActor.cleanUp(BPServiceActor.java:487)
	at org.apache.hadoop.hdfs.server.datanode.BPServiceActor.run(BPServiceActor.java:684)
	at java.lang.Thread.run(Thread.java:722)
2015-10-19 20:03:37,024 INFO  datanode.DataNode (BlockPoolManager.java:remove(99)) - Removed Block pool  (storage id unknown)
2015-10-19 20:03:37,024 WARN  datanode.DataNode (BPOfferService.java:getBlockPoolId(154)) - Block pool ID needed, but service not yet registered with NN
java.lang.Exception: trace
	at org.apache.hadoop.hdfs.server.datanode.BPOfferService.getBlockPoolId(BPOfferService.java:154)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.shutdownBlockPool(DataNode.java:778)
	at org.apache.hadoop.hdfs.server.datanode.BPOfferService.shutdownActor(BPOfferService.java:376)
	at org.apache.hadoop.hdfs.server.datanode.BPServiceActor.cleanUp(BPServiceActor.java:487)
	at org.apache.hadoop.hdfs.server.datanode.BPServiceActor.run(BPServiceActor.java:684)
	at java.lang.Thread.run(Thread.java:722)
2015-10-19 20:03:37,025 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:37,026 INFO  namenode.FSEditLog (FSEditLog.java:endCurrentLogSegment(992)) - Ending log segment 1
2015-10-19 20:03:37,032 INFO  namenode.FSEditLog (FSEditLog.java:printStatistics(650)) - Number of transactions: 2 Total time for transactions(ms): 1Number of transactions batched in Syncs: 0 Number of syncs: 3 SyncTimes(ms): 17 
2015-10-19 20:03:37,034 INFO  namenode.FileJournalManager (FileJournalManager.java:finalizeLogSegment(122)) - Finalizing edits file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/edits_inprogress_0000000000000000001 -> /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/edits_0000000000000000001-0000000000000000002
2015-10-19 20:03:37,035 WARN  blockmanagement.BlockManager (BlockManager.java:run(3014)) - ReplicationMonitor thread received InterruptedException.
java.lang.InterruptedException: sleep interrupted
	at java.lang.Thread.sleep(Native Method)
	at org.apache.hadoop.hdfs.server.blockmanagement.BlockManager$ReplicationMonitor.run(BlockManager.java:3012)
	at java.lang.Thread.run(Thread.java:722)
2015-10-19 20:03:37,039 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:37,043 INFO  namenode.FSNamesystem (FSNamesystem.java:stopStandbyServices(743)) - Stopping services started for standby state
2015-10-19 20:03:37,041 WARN  blockmanagement.DecommissionManager (DecommissionManager.java:run(78)) - Monitor interrupted: java.lang.InterruptedException: sleep interrupted
2015-10-19 20:03:37,045 INFO  ipc.Server (Server.java:stop(1992)) - Stopping server on 53151
2015-10-19 20:03:37,050 INFO  ipc.Server (Server.java:run(639)) - Stopping IPC Server listener on 53151
2015-10-19 20:03:37,050 INFO  ipc.Server (Server.java:run(781)) - Stopping IPC Server Responder
2015-10-19 20:03:37,074 INFO  mortbay.log (Slf4jLog.java:info(67)) - Stopped SelectChannelConnector@hadoop-VM:0
Formatting using clusterid: testClusterID
2015-10-19 20:03:37,288 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:37,291 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:37,297 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:37,298 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:37,298 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:37,299 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:37,299 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:37,299 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:37,300 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:37,300 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:37,309 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:37,310 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:37,310 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:37,311 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:37,315 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:37,316 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:37,317 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:37,317 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:37,318 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:37,339 INFO  namenode.NNStorage (NNStorage.java:format(531)) - Storage directory /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1 has been successfully formatted.
2015-10-19 20:03:37,347 INFO  namenode.FSImage (FSImageFormat.java:save(504)) - Saving image file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/fsimage.ckpt_0000000000000000000 using no compression
2015-10-19 20:03:37,352 INFO  namenode.FSImage (FSImageFormat.java:save(531)) - Image file of size 120 saved in 0 seconds.
2015-10-19 20:03:37,363 INFO  namenode.NNStorageRetentionManager (NNStorageRetentionManager.java:getImageTxIdToRetain(133)) - Going to retain 1 images with txid >= 0
2015-10-19 20:03:37,363 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(151)) - NameNode metrics system started (again)
2015-10-19 20:03:37,377 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(402)) - Only one image storage directory (dfs.namenode.name.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:37,378 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(407)) - Only one namespace edits storage directory (dfs.namenode.edits.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:37,380 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:37,380 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:37,394 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:37,400 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:37,401 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:37,410 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:37,410 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:37,411 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:37,412 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:37,417 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:37,421 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:37,422 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:37,422 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:37,423 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:37,425 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:37,427 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:37,428 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:37,429 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:37,429 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:37,443 INFO  common.Storage (Storage.java:tryLock(654)) - Lock on /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/in_use.lock acquired by nodename 5544@hadoop-VM
2015-10-19 20:03:37,447 INFO  namenode.FileJournalManager (FileJournalManager.java:recoverUnfinalizedSegments(284)) - Recovering unfinalized segments in /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current
2015-10-19 20:03:37,448 INFO  namenode.FSImage (FSImage.java:loadFSImage(628)) - No edit log streams selected.
2015-10-19 20:03:37,449 INFO  namenode.FSImage (FSImageFormat.java:load(168)) - Loading image file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/fsimage_0000000000000000000 using no compression
2015-10-19 20:03:37,449 INFO  namenode.FSImage (FSImageFormat.java:load(171)) - Number of files = 1
2015-10-19 20:03:37,451 INFO  namenode.FSImage (FSImageFormat.java:loadFilesUnderConstruction(361)) - Number of files under construction = 0
2015-10-19 20:03:37,455 INFO  namenode.FSImage (FSImageFormat.java:load(193)) - Image file of size 120 loaded in 0 seconds.
2015-10-19 20:03:37,457 INFO  namenode.FSImage (FSImage.java:loadFSImage(771)) - Loaded image for txid 0 from /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/fsimage_0000000000000000000
2015-10-19 20:03:37,458 INFO  namenode.FSEditLog (FSEditLog.java:startLogSegment(949)) - Starting log segment at 1
2015-10-19 20:03:37,481 INFO  namenode.NameCache (NameCache.java:initialized(143)) - initialized with 0 entries 0 lookups
2015-10-19 20:03:37,482 INFO  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(424)) - Finished loading FSImage in 52 msecs
2015-10-19 20:03:37,494 INFO  ipc.Server (Server.java:run(483)) - Starting Socket Reader #1 for port 45742
2015-10-19 20:03:37,499 INFO  namenode.FSNamesystem (FSNamesystem.java:registerMBean(4651)) - Registered FSNamesystemState MBean
2015-10-19 20:03:37,538 INFO  namenode.FSNamesystem (FSNamesystem.java:getCompleteBlocksTotal(4329)) - Number of blocks under construction: 0
2015-10-19 20:03:37,538 INFO  namenode.FSNamesystem (FSNamesystem.java:initializeReplQueues(3870)) - initializing replication queues
2015-10-19 20:03:37,543 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2221)) - Total number of blocks            = 0
2015-10-19 20:03:37,543 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2222)) - Number of invalid blocks          = 0
2015-10-19 20:03:37,544 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2223)) - Number of under-replicated blocks = 0
2015-10-19 20:03:37,544 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2224)) - Number of  over-replicated blocks = 0
2015-10-19 20:03:37,545 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2226)) - Number of blocks being written    = 0
2015-10-19 20:03:37,546 INFO  hdfs.StateChange (FSNamesystem.java:initializeReplQueues(3875)) - STATE* Replication Queue initialization scan for invalid, over- and under-replicated blocks completed in 7 msec
2015-10-19 20:03:37,547 INFO  hdfs.StateChange (FSNamesystem.java:leave(3847)) - STATE* Leaving safe mode after 0 secs.
2015-10-19 20:03:37,547 INFO  hdfs.StateChange (FSNamesystem.java:leave(3857)) - STATE* Network topology has 0 racks and 0 datanodes
2015-10-19 20:03:37,547 INFO  hdfs.StateChange (FSNamesystem.java:leave(3860)) - STATE* UnderReplicatedBlocks has 0 blocks
2015-10-19 20:03:37,550 WARN  util.MBeans (MBeans.java:register(65)) - Failed to register MBean "Hadoop:service=NameNode,name=NameNodeInfo-1": Instance already exists.
2015-10-19 20:03:37,581 INFO  http.HttpServer (HttpServer.java:addGlobalFilter(499)) - Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
2015-10-19 20:03:37,583 INFO  http.HttpServer (HttpServer.java:addFilter(477)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context hdfs
2015-10-19 20:03:37,584 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context logs
2015-10-19 20:03:37,585 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context static
2015-10-19 20:03:37,589 INFO  http.HttpServer (WebHdfsFileSystem.java:isEnabled(142)) - dfs.webhdfs.enabled = false
2015-10-19 20:03:37,601 INFO  http.HttpServer (HttpServer.java:start(657)) - Jetty bound to port 59352
2015-10-19 20:03:37,601 INFO  mortbay.log (Slf4jLog.java:info(67)) - jetty-6.1.26
2015-10-19 20:03:37,690 INFO  mortbay.log (Slf4jLog.java:info(67)) - Started SelectChannelConnector@hadoop-VM:59352
2015-10-19 20:03:37,694 INFO  namenode.NameNode (NameNode.java:setHttpServerAddress(394)) - Web-server up at: hadoop-VM:59352
2015-10-19 20:03:37,696 INFO  ipc.Server (Server.java:run(776)) - IPC Server Responder: starting
2015-10-19 20:03:37,698 INFO  ipc.Server (Server.java:run(607)) - IPC Server listener on 45742: starting
2015-10-19 20:03:37,728 INFO  namenode.NameNode (NameNode.java:startCommonServices(491)) - NameNode up at: hadoop-VM/127.0.1.1:45742
2015-10-19 20:03:37,728 INFO  namenode.FSNamesystem (FSNamesystem.java:startActiveServices(619)) - Starting services required for active state
2015-10-19 20:03:37,745 INFO  hdfs.TestHDFSServerPorts (TestHDFSServerPorts.java:testSecondaryNodePorts(351)) - = Starting 1 on: hadoop-VM:59352
2015-10-19 20:03:37,763 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(151)) - SecondaryNameNode metrics system started (again)
2015-10-19 20:03:37,930 INFO  common.Storage (Storage.java:tryLock(654)) - Lock on /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/dfs/namesecondary/in_use.lock acquired by nodename 5544@hadoop-VM
2015-10-19 20:03:37,934 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:37,935 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:37,937 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:37,938 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:37,938 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:37,939 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:37,939 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:37,939 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:37,940 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:37,941 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:37,941 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:37,942 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:37,942 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:37,942 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:37,944 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:37,952 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:37,953 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:37,953 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:37,954 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:37,961 INFO  http.HttpServer (HttpServer.java:addGlobalFilter(499)) - Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
2015-10-19 20:03:37,964 INFO  http.HttpServer (HttpServer.java:addFilter(477)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context secondary
2015-10-19 20:03:37,964 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context static
2015-10-19 20:03:37,965 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context logs
2015-10-19 20:03:37,967 INFO  http.HttpServer (HttpServer.java:start(660)) - HttpServer.start() threw a non Bind IOException
java.net.BindException: Port in use: hadoop-VM:59352
	at org.apache.hadoop.http.HttpServer.openListener(HttpServer.java:706)
	at org.apache.hadoop.http.HttpServer.start(HttpServer.java:656)
	at org.apache.hadoop.hdfs.server.namenode.SecondaryNameNode.initialize(SecondaryNameNode.java:253)
	at org.apache.hadoop.hdfs.server.namenode.SecondaryNameNode.(SecondaryNameNode.java:179)
	at org.apache.hadoop.hdfs.server.namenode.SecondaryNameNode.(SecondaryNameNode.java:166)
	at org.apache.hadoop.hdfs.TestHDFSServerPorts.canStartSecondaryNode(TestHDFSServerPorts.java:224)
	at org.apache.hadoop.hdfs.TestHDFSServerPorts.testSecondaryNodePorts(TestHDFSServerPorts.java:353)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
	at org.junit.runners.BlockJUnit4ClassRunner.runNotIgnored(BlockJUnit4ClassRunner.java:79)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:71)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:49)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
	at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:264)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:153)
	at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:124)
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
Caused by: java.net.BindException: Address already in use
	at sun.nio.ch.Net.bind0(Native Method)
	at sun.nio.ch.Net.bind(Net.java:344)
	at sun.nio.ch.Net.bind(Net.java:336)
	at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:199)
	at sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:74)
	at org.mortbay.jetty.nio.SelectChannelConnector.open(SelectChannelConnector.java:216)
	at org.apache.hadoop.http.HttpServer.openListener(HttpServer.java:702)
	... 29 more
2015-10-19 20:03:37,970 INFO  hdfs.TestHDFSServerPorts (TestHDFSServerPorts.java:testSecondaryNodePorts(358)) - = Starting 2 on: hadoop-VM:0
2015-10-19 20:03:37,971 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(151)) - SecondaryNameNode metrics system started (again)
2015-10-19 20:03:37,982 INFO  common.Storage (Storage.java:tryLock(654)) - Lock on /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/dfs/namesecondary/in_use.lock acquired by nodename 5544@hadoop-VM
2015-10-19 20:03:37,983 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:37,985 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:37,989 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:37,991 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:37,991 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:37,992 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:37,993 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:37,993 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:37,994 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:37,995 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:37,996 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:37,996 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:37,997 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:37,997 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:37,998 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:37,999 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:38,000 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:38,001 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:38,001 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:38,004 INFO  http.HttpServer (HttpServer.java:addGlobalFilter(499)) - Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
2015-10-19 20:03:38,006 INFO  http.HttpServer (HttpServer.java:addFilter(477)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context secondary
2015-10-19 20:03:38,007 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context logs
2015-10-19 20:03:38,007 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context static
2015-10-19 20:03:38,010 INFO  http.HttpServer (HttpServer.java:start(657)) - Jetty bound to port 42204
2015-10-19 20:03:38,011 INFO  mortbay.log (Slf4jLog.java:info(67)) - jetty-6.1.26
2015-10-19 20:03:38,094 INFO  mortbay.log (Slf4jLog.java:info(67)) - Started SelectChannelConnector@hadoop-VM:42204
2015-10-19 20:03:38,098 INFO  namenode.SecondaryNameNode (SecondaryNameNode.java:initialize(255)) - Web server init done
2015-10-19 20:03:38,099 INFO  namenode.SecondaryNameNode (SecondaryNameNode.java:initialize(261)) - Secondary Web-server up at: hadoop-VM:42204
2015-10-19 20:03:38,099 INFO  namenode.SecondaryNameNode (SecondaryNameNode.java:initialize(262)) - Checkpoint Period   :3600 secs (60 min)
2015-10-19 20:03:38,100 INFO  namenode.SecondaryNameNode (SecondaryNameNode.java:initialize(264)) - Log Size Trigger    :40000 txns
2015-10-19 20:03:38,150 INFO  mortbay.log (Slf4jLog.java:info(67)) - Stopped SelectChannelConnector@hadoop-VM:0
2015-10-19 20:03:38,152 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:38,154 INFO  namenode.FSEditLog (FSEditLog.java:endCurrentLogSegment(992)) - Ending log segment 1
2015-10-19 20:03:38,159 INFO  namenode.FSEditLog (FSEditLog.java:printStatistics(650)) - Number of transactions: 2 Total time for transactions(ms): 0Number of transactions batched in Syncs: 0 Number of syncs: 3 SyncTimes(ms): 19 
2015-10-19 20:03:38,161 INFO  namenode.FileJournalManager (FileJournalManager.java:finalizeLogSegment(122)) - Finalizing edits file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/edits_inprogress_0000000000000000001 -> /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/edits_0000000000000000001-0000000000000000002
2015-10-19 20:03:38,162 WARN  blockmanagement.BlockManager (BlockManager.java:run(3014)) - ReplicationMonitor thread received InterruptedException.
java.lang.InterruptedException: sleep interrupted
	at java.lang.Thread.sleep(Native Method)
	at org.apache.hadoop.hdfs.server.blockmanagement.BlockManager$ReplicationMonitor.run(BlockManager.java:3012)
	at java.lang.Thread.run(Thread.java:722)
2015-10-19 20:03:38,165 WARN  blockmanagement.DecommissionManager (DecommissionManager.java:run(78)) - Monitor interrupted: java.lang.InterruptedException: sleep interrupted
2015-10-19 20:03:38,168 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:38,171 INFO  namenode.FSNamesystem (FSNamesystem.java:stopStandbyServices(743)) - Stopping services started for standby state
2015-10-19 20:03:38,172 INFO  ipc.Server (Server.java:stop(1992)) - Stopping server on 45742
2015-10-19 20:03:38,173 INFO  ipc.Server (Server.java:run(639)) - Stopping IPC Server listener on 45742
2015-10-19 20:03:38,174 INFO  ipc.Server (Server.java:run(781)) - Stopping IPC Server Responder
2015-10-19 20:03:38,227 INFO  mortbay.log (Slf4jLog.java:info(67)) - Stopped SelectChannelConnector@hadoop-VM:0
Formatting using clusterid: testClusterID
2015-10-19 20:03:38,457 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:38,458 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:38,478 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:38,479 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:38,481 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:38,481 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:38,481 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:38,481 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:38,482 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:38,482 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:38,483 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:38,483 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:38,483 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:38,501 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:38,502 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:38,504 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:38,513 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:38,513 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:38,514 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:38,541 INFO  namenode.NNStorage (NNStorage.java:format(531)) - Storage directory /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1 has been successfully formatted.
2015-10-19 20:03:38,556 INFO  namenode.FSImage (FSImageFormat.java:save(504)) - Saving image file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/fsimage.ckpt_0000000000000000000 using no compression
2015-10-19 20:03:38,563 INFO  namenode.FSImage (FSImageFormat.java:save(531)) - Image file of size 120 saved in 0 seconds.
2015-10-19 20:03:38,576 INFO  namenode.NNStorageRetentionManager (NNStorageRetentionManager.java:getImageTxIdToRetain(133)) - Going to retain 1 images with txid >= 0
2015-10-19 20:03:38,578 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(151)) - NameNode metrics system started (again)
2015-10-19 20:03:38,598 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(402)) - Only one image storage directory (dfs.namenode.name.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:38,604 WARN  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(407)) - Only one namespace edits storage directory (dfs.namenode.edits.dir) configured. Beware of dataloss due to lack of redundant storage directories!
2015-10-19 20:03:38,605 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:38,607 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:38,631 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:38,633 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:38,633 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:38,634 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:38,634 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:38,635 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:38,636 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:38,637 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:38,637 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:38,638 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:38,639 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:38,639 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:38,640 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:38,642 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:38,642 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:38,642 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:38,643 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:38,655 INFO  common.Storage (Storage.java:tryLock(654)) - Lock on /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/in_use.lock acquired by nodename 5544@hadoop-VM
2015-10-19 20:03:38,658 INFO  namenode.FileJournalManager (FileJournalManager.java:recoverUnfinalizedSegments(284)) - Recovering unfinalized segments in /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current
2015-10-19 20:03:38,659 INFO  namenode.FSImage (FSImage.java:loadFSImage(628)) - No edit log streams selected.
2015-10-19 20:03:38,661 INFO  namenode.FSImage (FSImageFormat.java:load(168)) - Loading image file /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/fsimage_0000000000000000000 using no compression
2015-10-19 20:03:38,661 INFO  namenode.FSImage (FSImageFormat.java:load(171)) - Number of files = 1
2015-10-19 20:03:38,662 INFO  namenode.FSImage (FSImageFormat.java:loadFilesUnderConstruction(361)) - Number of files under construction = 0
2015-10-19 20:03:38,663 INFO  namenode.FSImage (FSImageFormat.java:load(193)) - Image file of size 120 loaded in 0 seconds.
2015-10-19 20:03:38,665 INFO  namenode.FSImage (FSImage.java:loadFSImage(771)) - Loaded image for txid 0 from /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/dfs/name1/current/fsimage_0000000000000000000
2015-10-19 20:03:38,682 INFO  namenode.FSEditLog (FSEditLog.java:startLogSegment(949)) - Starting log segment at 1
2015-10-19 20:03:38,713 INFO  namenode.NameCache (NameCache.java:initialized(143)) - initialized with 0 entries 0 lookups
2015-10-19 20:03:38,714 INFO  namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(424)) - Finished loading FSImage in 70 msecs
2015-10-19 20:03:38,725 INFO  namenode.FSNamesystem (FSNamesystem.java:registerMBean(4651)) - Registered FSNamesystemState MBean
2015-10-19 20:03:38,726 INFO  ipc.Server (Server.java:run(483)) - Starting Socket Reader #1 for port 35258
2015-10-19 20:03:38,802 INFO  namenode.FSNamesystem (FSNamesystem.java:getCompleteBlocksTotal(4329)) - Number of blocks under construction: 0
2015-10-19 20:03:38,803 INFO  namenode.FSNamesystem (FSNamesystem.java:initializeReplQueues(3870)) - initializing replication queues
2015-10-19 20:03:38,806 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2221)) - Total number of blocks            = 0
2015-10-19 20:03:38,807 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2222)) - Number of invalid blocks          = 0
2015-10-19 20:03:38,807 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2223)) - Number of under-replicated blocks = 0
2015-10-19 20:03:38,808 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2224)) - Number of  over-replicated blocks = 0
2015-10-19 20:03:38,809 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2226)) - Number of blocks being written    = 0
2015-10-19 20:03:38,809 INFO  hdfs.StateChange (FSNamesystem.java:initializeReplQueues(3875)) - STATE* Replication Queue initialization scan for invalid, over- and under-replicated blocks completed in 6 msec
2015-10-19 20:03:38,809 INFO  hdfs.StateChange (FSNamesystem.java:leave(3847)) - STATE* Leaving safe mode after 0 secs.
2015-10-19 20:03:38,809 INFO  hdfs.StateChange (FSNamesystem.java:leave(3857)) - STATE* Network topology has 0 racks and 0 datanodes
2015-10-19 20:03:38,810 INFO  hdfs.StateChange (FSNamesystem.java:leave(3860)) - STATE* UnderReplicatedBlocks has 0 blocks
2015-10-19 20:03:38,859 WARN  util.MBeans (MBeans.java:register(65)) - Failed to register MBean "Hadoop:service=NameNode,name=NameNodeInfo-2": Instance already exists.
2015-10-19 20:03:38,893 INFO  http.HttpServer (HttpServer.java:addGlobalFilter(499)) - Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
2015-10-19 20:03:38,894 INFO  http.HttpServer (HttpServer.java:addFilter(477)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context hdfs
2015-10-19 20:03:38,895 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context static
2015-10-19 20:03:38,895 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context logs
2015-10-19 20:03:38,897 INFO  http.HttpServer (WebHdfsFileSystem.java:isEnabled(142)) - dfs.webhdfs.enabled = false
2015-10-19 20:03:38,904 INFO  http.HttpServer (HttpServer.java:start(657)) - Jetty bound to port 39658
2015-10-19 20:03:38,910 INFO  mortbay.log (Slf4jLog.java:info(67)) - jetty-6.1.26
2015-10-19 20:03:39,011 INFO  mortbay.log (Slf4jLog.java:info(67)) - Started SelectChannelConnector@hadoop-VM:39658
2015-10-19 20:03:39,013 INFO  namenode.NameNode (NameNode.java:setHttpServerAddress(394)) - Web-server up at: hadoop-VM:39658
2015-10-19 20:03:39,021 INFO  ipc.Server (Server.java:run(776)) - IPC Server Responder: starting
2015-10-19 20:03:39,030 INFO  ipc.Server (Server.java:run(607)) - IPC Server listener on 35258: starting
2015-10-19 20:03:39,067 INFO  namenode.NameNode (NameNode.java:startCommonServices(491)) - NameNode up at: hadoop-VM/127.0.1.1:35258
2015-10-19 20:03:39,068 INFO  namenode.FSNamesystem (FSNamesystem.java:startActiveServices(619)) - Starting services required for active state
2015-10-19 20:03:39,070 INFO  hdfs.TestHDFSServerPorts (TestHDFSServerPorts.java:testBackupNodePorts(383)) - = Starting 1 on: hadoop-VM:39658
2015-10-19 20:03:39,073 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(151)) - BackupNode metrics system started (again)
2015-10-19 20:03:39,613 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:39,614 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:39,617 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:39,618 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:39,618 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:39,618 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:39,619 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:39,619 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:39,619 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:39,619 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:39,620 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:39,620 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:39,620 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:39,621 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:39,621 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:39,622 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:39,622 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:39,623 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:39,623 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:39,631 INFO  common.Storage (Storage.java:tryLock(654)) - Lock on /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/backupNode/name2/in_use.lock acquired by nodename 5544@hadoop-VM
2015-10-19 20:03:39,634 INFO  namenode.FSImage (BackupImage.java:recoverCreateRead(122)) - Storage directory /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/backupNode/name2 is not formatted.
2015-10-19 20:03:39,634 INFO  namenode.FSImage (BackupImage.java:recoverCreateRead(123)) - Formatting ...
2015-10-19 20:03:39,640 INFO  ipc.Server (Server.java:run(483)) - Starting Socket Reader #1 for port 40245
2015-10-19 20:03:39,654 INFO  namenode.FSNamesystem (FSNamesystem.java:registerMBean(4651)) - Registered FSNamesystemState MBean
2015-10-19 20:03:39,666 INFO  namenode.FSNamesystem (FSNamesystem.java:getCompleteBlocksTotal(4329)) - Number of blocks under construction: 0
2015-10-19 20:03:39,667 INFO  namenode.FSNamesystem (FSNamesystem.java:initializeReplQueues(3870)) - initializing replication queues
2015-10-19 20:03:39,670 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2221)) - Total number of blocks            = 0
2015-10-19 20:03:39,671 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2222)) - Number of invalid blocks          = 0
2015-10-19 20:03:39,672 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2223)) - Number of under-replicated blocks = 0
2015-10-19 20:03:39,672 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2224)) - Number of  over-replicated blocks = 0
2015-10-19 20:03:39,672 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2226)) - Number of blocks being written    = 0
2015-10-19 20:03:39,673 INFO  hdfs.StateChange (FSNamesystem.java:initializeReplQueues(3875)) - STATE* Replication Queue initialization scan for invalid, over- and under-replicated blocks completed in 6 msec
2015-10-19 20:03:39,673 INFO  hdfs.StateChange (FSNamesystem.java:leave(3847)) - STATE* Leaving safe mode after 0 secs.
2015-10-19 20:03:39,674 INFO  hdfs.StateChange (FSNamesystem.java:leave(3857)) - STATE* Network topology has 0 racks and 0 datanodes
2015-10-19 20:03:39,674 INFO  hdfs.StateChange (FSNamesystem.java:leave(3860)) - STATE* UnderReplicatedBlocks has 0 blocks
2015-10-19 20:03:39,688 ERROR lib.MethodMetric (MethodMetric.java:snapshot(116)) - Error invoking method getTransactionsSinceLastLogRoll
java.lang.reflect.InvocationTargetException
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at org.apache.hadoop.metrics2.lib.MethodMetric$2.snapshot(MethodMetric.java:110)
	at org.apache.hadoop.metrics2.lib.MethodMetric.snapshot(MethodMetric.java:141)
	at org.apache.hadoop.metrics2.lib.MetricsRegistry.snapshot(MetricsRegistry.java:387)
	at org.apache.hadoop.metrics2.lib.MetricsSourceBuilder$1.getMetrics(MetricsSourceBuilder.java:78)
	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.getMetrics(MetricsSourceAdapter.java:194)
	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.updateJmxCache(MetricsSourceAdapter.java:171)
	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.getMBeanInfo(MetricsSourceAdapter.java:150)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getNewMBeanClassName(DefaultMBeanServerInterceptor.java:333)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:319)
	at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:513)
	at org.apache.hadoop.metrics2.util.MBeans.register(MBeans.java:58)
	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.startMBeans(MetricsSourceAdapter.java:219)
	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.start(MetricsSourceAdapter.java:95)
	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.registerSource(MetricsSystemImpl.java:244)
	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.register(MetricsSystemImpl.java:222)
	at org.apache.hadoop.metrics2.MetricsSystem.register(MetricsSystem.java:54)
	at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.startCommonServices(FSNamesystem.java:598)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.startCommonServices(NameNode.java:479)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.initialize(NameNode.java:443)
	at org.apache.hadoop.hdfs.server.namenode.BackupNode.initialize(BackupNode.java:147)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.(NameNode.java:597)
	at org.apache.hadoop.hdfs.server.namenode.BackupNode.(BackupNode.java:87)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.createNameNode(NameNode.java:1109)
	at org.apache.hadoop.hdfs.TestHDFSServerPorts.startBackupNode(TestHDFSServerPorts.java:143)
	at org.apache.hadoop.hdfs.TestHDFSServerPorts.canStartBackupNode(TestHDFSServerPorts.java:242)
	at org.apache.hadoop.hdfs.TestHDFSServerPorts.testBackupNodePorts(TestHDFSServerPorts.java:386)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
	at org.junit.runners.BlockJUnit4ClassRunner.runNotIgnored(BlockJUnit4ClassRunner.java:79)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:71)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:49)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
	at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:264)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:153)
	at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:124)
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
Caused by: java.lang.IllegalStateException: Bad state: UNINITIALIZED
	at com.google.common.base.Preconditions.checkState(Preconditions.java:172)
	at org.apache.hadoop.hdfs.server.namenode.FSEditLog.getCurSegmentTxId(FSEditLog.java:472)
	at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getTransactionsSinceLastLogRoll(FSNamesystem.java:3500)
	... 53 more
2015-10-19 20:03:39,695 INFO  http.HttpServer (HttpServer.java:addGlobalFilter(499)) - Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
2015-10-19 20:03:39,697 INFO  http.HttpServer (HttpServer.java:addFilter(477)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context hdfs
2015-10-19 20:03:39,698 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context logs
2015-10-19 20:03:39,698 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context static
2015-10-19 20:03:39,700 INFO  http.HttpServer (WebHdfsFileSystem.java:isEnabled(142)) - dfs.webhdfs.enabled = false
2015-10-19 20:03:39,704 INFO  http.HttpServer (HttpServer.java:start(660)) - HttpServer.start() threw a non Bind IOException
java.net.BindException: Port in use: hadoop-VM:39658
	at org.apache.hadoop.http.HttpServer.openListener(HttpServer.java:706)
	at org.apache.hadoop.http.HttpServer.start(HttpServer.java:656)
	at org.apache.hadoop.hdfs.server.namenode.NameNodeHttpServer.start(NameNodeHttpServer.java:159)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.startHttpServer(NameNode.java:536)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.startCommonServices(NameNode.java:480)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.initialize(NameNode.java:443)
	at org.apache.hadoop.hdfs.server.namenode.BackupNode.initialize(BackupNode.java:147)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.(NameNode.java:597)
	at org.apache.hadoop.hdfs.server.namenode.BackupNode.(BackupNode.java:87)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.createNameNode(NameNode.java:1109)
	at org.apache.hadoop.hdfs.TestHDFSServerPorts.startBackupNode(TestHDFSServerPorts.java:143)
	at org.apache.hadoop.hdfs.TestHDFSServerPorts.canStartBackupNode(TestHDFSServerPorts.java:242)
	at org.apache.hadoop.hdfs.TestHDFSServerPorts.testBackupNodePorts(TestHDFSServerPorts.java:386)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
	at org.junit.runners.BlockJUnit4ClassRunner.runNotIgnored(BlockJUnit4ClassRunner.java:79)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:71)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:49)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
	at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:264)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:153)
	at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:124)
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
Caused by: java.net.BindException: Address already in use
	at sun.nio.ch.Net.bind0(Native Method)
	at sun.nio.ch.Net.bind(Net.java:344)
	at sun.nio.ch.Net.bind(Net.java:336)
	at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:199)
	at sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:74)
	at org.mortbay.jetty.nio.SelectChannelConnector.open(SelectChannelConnector.java:216)
	at org.apache.hadoop.http.HttpServer.openListener(HttpServer.java:702)
	... 35 more
2015-10-19 20:03:39,706 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:39,706 WARN  blockmanagement.BlockManager (BlockManager.java:run(3014)) - ReplicationMonitor thread received InterruptedException.
java.lang.InterruptedException: sleep interrupted
	at java.lang.Thread.sleep(Native Method)
	at org.apache.hadoop.hdfs.server.blockmanagement.BlockManager$ReplicationMonitor.run(BlockManager.java:3012)
	at java.lang.Thread.run(Thread.java:722)
2015-10-19 20:03:39,709 WARN  blockmanagement.DecommissionManager (DecommissionManager.java:run(78)) - Monitor interrupted: java.lang.InterruptedException: sleep interrupted
2015-10-19 20:03:39,709 INFO  namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(682)) - Stopping services started for active state
2015-10-19 20:03:39,710 INFO  namenode.FSNamesystem (FSNamesystem.java:stopStandbyServices(743)) - Stopping services started for standby state
2015-10-19 20:03:39,711 INFO  ipc.Server (Server.java:stop(1992)) - Stopping server on 40245
2015-10-19 20:03:39,712 INFO  hdfs.TestHDFSServerPorts (TestHDFSServerPorts.java:testBackupNodePorts(392)) - = Starting 2 on: hadoop-VM:0
2015-10-19 20:03:39,714 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(151)) - BackupNode metrics system started (again)
2015-10-19 20:03:39,730 INFO  util.HostsFileReader (HostsFileReader.java:refresh(82)) - Refreshing hosts (include/exclude) list
2015-10-19 20:03:39,731 INFO  blockmanagement.DatanodeManager (DatanodeManager.java:(177)) - dfs.block.invalidate.limit=1000
2015-10-19 20:03:39,733 INFO  blockmanagement.BlockManager (BlockManager.java:createBlockTokenSecretManager(311)) - dfs.block.access.token.enable=false
2015-10-19 20:03:39,734 INFO  blockmanagement.BlockManager (BlockManager.java:(297)) - defaultReplication         = 3
2015-10-19 20:03:39,735 INFO  blockmanagement.BlockManager (BlockManager.java:(298)) - maxReplication             = 512
2015-10-19 20:03:39,735 INFO  blockmanagement.BlockManager (BlockManager.java:(299)) - minReplication             = 1
2015-10-19 20:03:39,735 INFO  blockmanagement.BlockManager (BlockManager.java:(300)) - maxReplicationStreams      = 2
2015-10-19 20:03:39,735 INFO  blockmanagement.BlockManager (BlockManager.java:(301)) - shouldCheckForEnoughRacks  = false
2015-10-19 20:03:39,735 INFO  blockmanagement.BlockManager (BlockManager.java:(302)) - replicationRecheckInterval = 3000
2015-10-19 20:03:39,736 INFO  blockmanagement.BlockManager (BlockManager.java:(303)) - encryptDataTransfer        = false
2015-10-19 20:03:39,736 INFO  namenode.FSNamesystem (FSNamesystem.java:(456)) - fsOwner             = felix (auth:SIMPLE)
2015-10-19 20:03:39,736 INFO  namenode.FSNamesystem (FSNamesystem.java:(457)) - supergroup          = supergroup
2015-10-19 20:03:39,737 INFO  namenode.FSNamesystem (FSNamesystem.java:(458)) - isPermissionEnabled = true
2015-10-19 20:03:39,737 INFO  namenode.FSNamesystem (FSNamesystem.java:(472)) - HA Enabled: false
2015-10-19 20:03:39,738 INFO  namenode.FSNamesystem (FSNamesystem.java:(493)) - Append Enabled: true
2015-10-19 20:03:39,738 INFO  namenode.NameNode (FSDirectory.java:(142)) - Caching file names occuring more than 10 times 
2015-10-19 20:03:39,739 INFO  namenode.FSNamesystem (FSNamesystem.java:(3750)) - dfs.namenode.safemode.threshold-pct = 0.9990000128746033
2015-10-19 20:03:39,739 INFO  namenode.FSNamesystem (FSNamesystem.java:(3751)) - dfs.namenode.safemode.min.datanodes = 0
2015-10-19 20:03:39,739 INFO  namenode.FSNamesystem (FSNamesystem.java:(3752)) - dfs.namenode.safemode.extension     = 30000
2015-10-19 20:03:39,747 INFO  common.Storage (Storage.java:tryLock(654)) - Lock on /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/backupNode/name2/in_use.lock acquired by nodename 5544@hadoop-VM
2015-10-19 20:03:39,747 INFO  namenode.FSImage (BackupImage.java:recoverCreateRead(122)) - Storage directory /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/backupNode/name2 is not formatted.
2015-10-19 20:03:39,747 INFO  namenode.FSImage (BackupImage.java:recoverCreateRead(123)) - Formatting ...
2015-10-19 20:03:39,757 INFO  ipc.Server (Server.java:run(483)) - Starting Socket Reader #1 for port 40245
2015-10-19 20:03:39,775 INFO  namenode.FSNamesystem (FSNamesystem.java:registerMBean(4651)) - Registered FSNamesystemState MBean
2015-10-19 20:03:39,785 INFO  namenode.FSNamesystem (FSNamesystem.java:getCompleteBlocksTotal(4329)) - Number of blocks under construction: 0
2015-10-19 20:03:39,785 INFO  namenode.FSNamesystem (FSNamesystem.java:initializeReplQueues(3870)) - initializing replication queues
2015-10-19 20:03:39,790 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2221)) - Total number of blocks            = 0
2015-10-19 20:03:39,791 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2222)) - Number of invalid blocks          = 0
2015-10-19 20:03:39,791 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2223)) - Number of under-replicated blocks = 0
2015-10-19 20:03:39,791 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2224)) - Number of  over-replicated blocks = 0
2015-10-19 20:03:39,792 INFO  blockmanagement.BlockManager (BlockManager.java:processMisReplicatedBlocks(2226)) - Number of blocks being written    = 0
2015-10-19 20:03:39,792 INFO  hdfs.StateChange (FSNamesystem.java:initializeReplQueues(3875)) - STATE* Replication Queue initialization scan for invalid, over- and under-replicated blocks completed in 6 msec
2015-10-19 20:03:39,793 INFO  hdfs.StateChange (FSNamesystem.java:leave(3847)) - STATE* Leaving safe mode after 0 secs.
2015-10-19 20:03:39,793 INFO  hdfs.StateChange (FSNamesystem.java:leave(3857)) - STATE* Network topology has 0 racks and 0 datanodes
2015-10-19 20:03:39,793 INFO  hdfs.StateChange (FSNamesystem.java:leave(3860)) - STATE* UnderReplicatedBlocks has 0 blocks
2015-10-19 20:03:39,811 ERROR lib.MethodMetric (MethodMetric.java:snapshot(116)) - Error invoking method getTransactionsSinceLastLogRoll
java.lang.reflect.InvocationTargetException
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at org.apache.hadoop.metrics2.lib.MethodMetric$2.snapshot(MethodMetric.java:110)
	at org.apache.hadoop.metrics2.lib.MethodMetric.snapshot(MethodMetric.java:141)
	at org.apache.hadoop.metrics2.lib.MetricsRegistry.snapshot(MetricsRegistry.java:387)
	at org.apache.hadoop.metrics2.lib.MetricsSourceBuilder$1.getMetrics(MetricsSourceBuilder.java:78)
	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.getMetrics(MetricsSourceAdapter.java:194)
	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.updateJmxCache(MetricsSourceAdapter.java:171)
	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.getMBeanInfo(MetricsSourceAdapter.java:150)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getNewMBeanClassName(DefaultMBeanServerInterceptor.java:333)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:319)
	at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:513)
	at org.apache.hadoop.metrics2.util.MBeans.register(MBeans.java:58)
	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.startMBeans(MetricsSourceAdapter.java:219)
	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.start(MetricsSourceAdapter.java:95)
	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.registerSource(MetricsSystemImpl.java:244)
	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.register(MetricsSystemImpl.java:222)
	at org.apache.hadoop.metrics2.MetricsSystem.register(MetricsSystem.java:54)
	at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.startCommonServices(FSNamesystem.java:598)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.startCommonServices(NameNode.java:479)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.initialize(NameNode.java:443)
	at org.apache.hadoop.hdfs.server.namenode.BackupNode.initialize(BackupNode.java:147)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.(NameNode.java:597)
	at org.apache.hadoop.hdfs.server.namenode.BackupNode.(BackupNode.java:87)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.createNameNode(NameNode.java:1109)
	at org.apache.hadoop.hdfs.TestHDFSServerPorts.startBackupNode(TestHDFSServerPorts.java:143)
	at org.apache.hadoop.hdfs.TestHDFSServerPorts.canStartBackupNode(TestHDFSServerPorts.java:242)
	at org.apache.hadoop.hdfs.TestHDFSServerPorts.testBackupNodePorts(TestHDFSServerPorts.java:395)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
	at org.junit.runners.BlockJUnit4ClassRunner.runNotIgnored(BlockJUnit4ClassRunner.java:79)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:71)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:49)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
	at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:264)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:153)
	at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:124)
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
Caused by: java.lang.IllegalStateException: Bad state: UNINITIALIZED
	at com.google.common.base.Preconditions.checkState(Preconditions.java:172)
	at org.apache.hadoop.hdfs.server.namenode.FSEditLog.getCurSegmentTxId(FSEditLog.java:472)
	at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getTransactionsSinceLastLogRoll(FSNamesystem.java:3500)
	... 53 more
2015-10-19 20:03:39,817 INFO  http.HttpServer (HttpServer.java:addGlobalFilter(499)) - Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
2015-10-19 20:03:39,819 INFO  http.HttpServer (HttpServer.java:addFilter(477)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context hdfs
2015-10-19 20:03:39,820 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context logs
2015-10-19 20:03:39,820 INFO  http.HttpServer (HttpServer.java:addFilter(484)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context static
2015-10-19 20:03:39,821 INFO  http.HttpServer (WebHdfsFileSystem.java:isEnabled(142)) - dfs.webhdfs.enabled = false
2015-10-19 20:03:39,824 INFO  http.HttpServer (HttpServer.java:start(657)) - Jetty bound to port 55961
2015-10-19 20:03:39,825 INFO  mortbay.log (Slf4jLog.java:info(67)) - jetty-6.1.26
2015-10-19 20:03:39,905 INFO  mortbay.log (Slf4jLog.java:info(67)) - Started SelectChannelConnector@hadoop-VM:55961
2015-10-19 20:03:39,906 INFO  ipc.Server (Server.java:run(776)) - IPC Server Responder: starting
2015-10-19 20:03:39,927 INFO  namenode.NameNode (NameNode.java:startCommonServices(491)) - Backup Node up at: hadoop-VM/127.0.1.1:40245
2015-10-19 20:03:39,928 INFO  ipc.Server (Server.java:run(607)) - IPC Server listener on 40245: starting
2015-10-19 20:03:39,956 INFO  hdfs.StateChange (FSNamesystem.java:reportStatus(4094)) - STATE* Safe mode is ON. 
Use "hdfs dfsadmin -safemode leave" to turn safe mode off.
2015-10-19 20:03:39,957 INFO  namenode.FileJournalManager (FileJournalManager.java:recoverUnfinalizedSegments(284)) - Recovering unfinalized segments in /home/felix/.jenkins/jobs/fail/workspace/hadoop-hdfs-project/hadoop-hdfs/target/test/data/backupNode/name2/current
2015-10-19 20:03:40,006 INFO  namenode.FSEditLog (FSEditLog.java:registerBackupNode(1106)) - Registering new backup node: NamenodeRegistration(hadoop-VM:40245, role=Backup Node)
2015-10-19 20:03:40,020 INFO  namenode.Checkpointer (Checkpointer.java:initialize(102)) - Checkpoint Period : 3600 secs (60 min)
2015-10-19 20:03:40,020 INFO  namenode.Checkpointer (Checkpointer.java:initialize(105)) - Transactions count is  : 40000, to trigger checkpoint
2015-10-19 20:03:40,021 INFO  namenode.FSNamesystem (FSNamesystem.java:startActiveServices(619)) - Starting services required for active state
2015-10-19 20:03:40,022 FATAL namenode.NameNode (NameNode.java:doImmediateShutdown(1270)) - Error encountered requiring NN shutdown. Shutting down immediately.
org.apache.hadoop.ipc.StandbyException: Operation category READ is not supported at the BackupNode
	at org.apache.hadoop.hdfs.server.namenode.BackupNode$BNHAContext.checkOperation(BackupNode.java:443)
	at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.checkOperation(FSNamesystem.java:759)
	at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getServerDefaults(FSNamesystem.java:1019)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.startTrashEmptier(NameNode.java:514)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.access$100(NameNode.java:121)
	at org.apache.hadoop.hdfs.server.namenode.NameNode$NameNodeHAContext.startActiveServices(NameNode.java:1295)
	at org.apache.hadoop.hdfs.server.namenode.ha.ActiveState.enterState(ActiveState.java:61)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.(NameNode.java:599)
	at org.apache.hadoop.hdfs.server.namenode.BackupNode.(BackupNode.java:87)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.createNameNode(NameNode.java:1109)
	at org.apache.hadoop.hdfs.TestHDFSServerPorts.startBackupNode(TestHDFSServerPorts.java:143)
	at org.apache.hadoop.hdfs.TestHDFSServerPorts.canStartBackupNode(TestHDFSServerPorts.java:242)
	at org.apache.hadoop.hdfs.TestHDFSServerPorts.testBackupNodePorts(TestHDFSServerPorts.java:395)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
	at org.junit.runners.BlockJUnit4ClassRunner.runNotIgnored(BlockJUnit4ClassRunner.java:79)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:71)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:49)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
	at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:264)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:153)
	at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:124)
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
2015-10-19 20:03:40,036 INFO  util.ExitUtil (ExitUtil.java:terminate(84)) - Exiting with status 1
2015-10-19 20:03:40,044 INFO  namenode.FSNamesystem (FSNamesystem.java:startCheckpoint(4431)) - Start checkpoint for hadoop-VM:40245
2015-10-19 20:03:40,045 INFO  namenode.FSEditLog (FSEditLog.java:rollEditLog(903)) - Rolling edit logs.
2015-10-19 20:03:40,045 INFO  namenode.FSEditLog (FSEditLog.java:endCurrentLogSegment(992)) - Ending log segment 1