[
https://issues.apache.org/jira/browse/HDFS-12378?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16167111#comment-16167111
]
Hadoop QA commented on HDFS-12378:
----------------------------------
| (x) *{color:red}-1 overall{color}* |
\\
\\
|| Vote || Subsystem || Runtime || Comment ||
| {color:blue}0{color} | {color:blue} reexec {color} | {color:blue} 0m
38s{color} | {color:blue} Docker mode activated. {color} |
|| || || || {color:brown} Prechecks {color} ||
| {color:green}+1{color} | {color:green} @author {color} | {color:green} 0m
0s{color} | {color:green} The patch does not contain any @author tags. {color} |
| {color:red}-1{color} | {color:red} test4tests {color} | {color:red} 0m
0s{color} | {color:red} The patch doesn't appear to include any new or modified
tests. Please justify why no new tests are needed for this patch. Also please
list what manual steps were performed to verify this patch. {color} |
|| || || || {color:brown} trunk Compile Tests {color} ||
| {color:green}+1{color} | {color:green} mvninstall {color} | {color:green} 18m
41s{color} | {color:green} trunk passed {color} |
| {color:green}+1{color} | {color:green} compile {color} | {color:green} 1m
13s{color} | {color:green} trunk passed {color} |
| {color:green}+1{color} | {color:green} checkstyle {color} | {color:green} 0m
47s{color} | {color:green} trunk passed {color} |
| {color:green}+1{color} | {color:green} mvnsite {color} | {color:green} 1m
17s{color} | {color:green} trunk passed {color} |
| {color:green}+1{color} | {color:green} findbugs {color} | {color:green} 2m
8s{color} | {color:green} trunk passed {color} |
| {color:green}+1{color} | {color:green} javadoc {color} | {color:green} 0m
55s{color} | {color:green} trunk passed {color} |
|| || || || {color:brown} Patch Compile Tests {color} ||
| {color:green}+1{color} | {color:green} mvninstall {color} | {color:green} 1m
5s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} compile {color} | {color:green} 1m
3s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} javac {color} | {color:green} 1m
3s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} checkstyle {color} | {color:green} 0m
42s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} mvnsite {color} | {color:green} 1m
5s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} whitespace {color} | {color:green} 0m
0s{color} | {color:green} The patch has no whitespace issues. {color} |
| {color:green}+1{color} | {color:green} findbugs {color} | {color:green} 2m
6s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} javadoc {color} | {color:green} 0m
51s{color} | {color:green} the patch passed {color} |
|| || || || {color:brown} Other Tests {color} ||
| {color:red}-1{color} | {color:red} unit {color} | {color:red}117m 26s{color}
| {color:red} hadoop-hdfs in the patch failed. {color} |
| {color:green}+1{color} | {color:green} asflicense {color} | {color:green} 0m
21s{color} | {color:green} The patch does not generate ASF License warnings.
{color} |
| {color:black}{color} | {color:black} {color} | {color:black}152m 0s{color} |
{color:black} {color} |
\\
\\
|| Reason || Tests ||
| Failed junit tests |
hadoop.hdfs.server.datanode.TestDataNodeVolumeFailureReporting |
| | hadoop.hdfs.server.namenode.ha.TestEditLogTailer |
| | hadoop.hdfs.TestDFSUpgrade |
| | hadoop.hdfs.TestLeaseRecoveryStriped |
| | hadoop.hdfs.TestReconstructStripedFile |
| | hadoop.hdfs.server.namenode.TestNameNodeMetadataConsistency |
| | hadoop.hdfs.TestReadWhileWriting |
| | hadoop.hdfs.server.namenode.metrics.TestNameNodeMetrics |
| Timed out junit tests | org.apache.hadoop.hdfs.TestWriteReadStripedFile |
\\
\\
|| Subsystem || Report/Notes ||
| Docker | Image:yetus/hadoop:71bbb86 |
| JIRA Issue | HDFS-12378 |
| JIRA Patch URL |
https://issues.apache.org/jira/secure/attachment/12887182/HDFS-12378.01.patch |
| Optional Tests | asflicense compile javac javadoc mvninstall mvnsite
unit findbugs checkstyle |
| uname | Linux 5f8d457ecde9 3.13.0-116-generic #163-Ubuntu SMP Fri Mar 31
14:13:22 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux |
| Build tool | maven |
| Personality | /testptch/hadoop/patchprocess/precommit/personality/provided.sh
|
| git revision | trunk / 7ee02d1 |
| Default Java | 1.8.0_144 |
| findbugs | v3.1.0-RC1 |
| unit |
https://builds.apache.org/job/PreCommit-HDFS-Build/21142/artifact/patchprocess/patch-unit-hadoop-hdfs-project_hadoop-hdfs.txt
|
| Test Results |
https://builds.apache.org/job/PreCommit-HDFS-Build/21142/testReport/ |
| modules | C: hadoop-hdfs-project/hadoop-hdfs U:
hadoop-hdfs-project/hadoop-hdfs |
| Console output |
https://builds.apache.org/job/PreCommit-HDFS-Build/21142/console |
| Powered by | Apache Yetus 0.6.0-SNAPSHOT http://yetus.apache.org |
This message was automatically generated.
> TestClientProtocolForPipelineRecovery#testZeroByteBlockRecovery fails on trunk
> ------------------------------------------------------------------------------
>
> Key: HDFS-12378
> URL: https://issues.apache.org/jira/browse/HDFS-12378
> Project: Hadoop HDFS
> Issue Type: Bug
> Components: test
> Affects Versions: 3.0.0-alpha4
> Reporter: Xiao Chen
> Assignee: Lei (Eddy) Xu
> Priority: Blocker
> Labels: flaky-test
> Attachments: HDFS-12378.00.patch, HDFS-12378.01.patch
>
>
> Saw on
> https://builds.apache.org/job/PreCommit-HDFS-Build/20928/testReport/org.apache.hadoop.hdfs/TestClientProtocolForPipelineRecovery/testZeroByteBlockRecovery/:
> Error Message
> {noformat}
> Failed to replace a bad datanode on the existing pipeline due to no more good
> datanodes being available to try. (Nodes:
> current=[DatanodeInfoWithStorage[127.0.0.1:51925,DS-274e8cc9-280b-4370-b494-6a4f0d67ccf4,DISK]],
>
> original=[DatanodeInfoWithStorage[127.0.0.1:51925,DS-274e8cc9-280b-4370-b494-6a4f0d67ccf4,DISK]]).
> The current failed datanode replacement policy is ALWAYS, and a client may
> configure this via
> 'dfs.client.block.write.replace-datanode-on-failure.policy' in its
> configuration.
> {noformat}
> Stacktrace
> {noformat}
> java.io.IOException: Failed to replace a bad datanode on the existing
> pipeline due to no more good datanodes being available to try. (Nodes:
> current=[DatanodeInfoWithStorage[127.0.0.1:51925,DS-274e8cc9-280b-4370-b494-6a4f0d67ccf4,DISK]],
>
> original=[DatanodeInfoWithStorage[127.0.0.1:51925,DS-274e8cc9-280b-4370-b494-6a4f0d67ccf4,DISK]]).
> The current failed datanode replacement policy is ALWAYS, and a client may
> configure this via
> 'dfs.client.block.write.replace-datanode-on-failure.policy' in its
> configuration.
> at
> org.apache.hadoop.hdfs.DataStreamer.findNewDatanode(DataStreamer.java:1322)
> at
> org.apache.hadoop.hdfs.DataStreamer.addDatanode2ExistingPipeline(DataStreamer.java:1388)
> at
> org.apache.hadoop.hdfs.DataStreamer.handleDatanodeReplacement(DataStreamer.java:1587)
> at
> org.apache.hadoop.hdfs.DataStreamer.setupPipelineInternal(DataStreamer.java:1488)
> at
> org.apache.hadoop.hdfs.DataStreamer.setupPipelineForAppendOrRecovery(DataStreamer.java:1470)
> at
> org.apache.hadoop.hdfs.DataStreamer.processDatanodeOrExternalError(DataStreamer.java:1274)
> at org.apache.hadoop.hdfs.DataStreamer.run(DataStreamer.java:684)
> {noformat}
> Standard Output
> {noformat}
> 2017-08-30 18:02:37,714 [main] INFO hdfs.MiniDFSCluster
> (MiniDFSCluster.java:<init>(469)) - starting cluster: numNameNodes=1,
> numDataNodes=3
> Formatting using clusterid: testClusterID
> 2017-08-30 18:02:37,716 [main] INFO namenode.FSEditLog
> (FSEditLog.java:newInstance(224)) - Edit logging is async:false
> 2017-08-30 18:02:37,716 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:<init>(742)) - KeyProvider: null
> 2017-08-30 18:02:37,716 [main] INFO namenode.FSNamesystem
> (FSNamesystemLock.java:<init>(120)) - fsLock is fair: true
> 2017-08-30 18:02:37,716 [main] INFO namenode.FSNamesystem
> (FSNamesystemLock.java:<init>(136)) - Detailed lock hold time metrics
> enabled: false
> 2017-08-30 18:02:37,717 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:<init>(763)) - fsOwner = jenkins (auth:SIMPLE)
> 2017-08-30 18:02:37,717 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:<init>(764)) - supergroup = supergroup
> 2017-08-30 18:02:37,717 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:<init>(765)) - isPermissionEnabled = true
> 2017-08-30 18:02:37,717 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:<init>(776)) - HA Enabled: false
> 2017-08-30 18:02:37,718 [main] INFO common.Util
> (Util.java:isDiskStatsEnabled(395)) -
> dfs.datanode.fileio.profiling.sampling.percentage set to 0. Disabling file IO
> profiling
> 2017-08-30 18:02:37,718 [main] INFO blockmanagement.DatanodeManager
> (DatanodeManager.java:<init>(301)) - dfs.block.invalidate.limit:
> configured=1000, counted=60, effected=1000
> 2017-08-30 18:02:37,718 [main] INFO blockmanagement.DatanodeManager
> (DatanodeManager.java:<init>(309)) -
> dfs.namenode.datanode.registration.ip-hostname-check=true
> 2017-08-30 18:02:37,719 [main] INFO blockmanagement.BlockManager
> (InvalidateBlocks.java:printBlockDeletionTime(76)) -
> dfs.namenode.startup.delay.block.deletion.sec is set to 000:00:00:00.000
> 2017-08-30 18:02:37,719 [main] INFO blockmanagement.BlockManager
> (InvalidateBlocks.java:printBlockDeletionTime(82)) - The block deletion will
> start around 2017 Aug 30 18:02:37
> 2017-08-30 18:02:37,719 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
> BlocksMap
> 2017-08-30 18:02:37,719 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
> 2017-08-30 18:02:37,720 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(397)) - 2.0% max memory 1.8 GB = 36.4 MB
> 2017-08-30 18:02:37,720 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(402)) - capacity = 2^22 = 4194304
> entries
> 2017-08-30 18:02:37,726 [main] INFO blockmanagement.BlockManager
> (BlockManager.java:createBlockTokenSecretManager(560)) -
> dfs.block.access.token.enable = false
> 2017-08-30 18:02:37,726 [main] INFO Configuration.deprecation
> (Configuration.java:logDeprecation(1285)) - No unit for
> dfs.namenode.safemode.extension(0) assuming MILLISECONDS
> 2017-08-30 18:02:37,727 [main] INFO blockmanagement.BlockManagerSafeMode
> (BlockManagerSafeMode.java:<init>(161)) - dfs.namenode.safemode.threshold-pct
> = 0.9990000128746033
> 2017-08-30 18:02:37,727 [main] INFO blockmanagement.BlockManagerSafeMode
> (BlockManagerSafeMode.java:<init>(162)) - dfs.namenode.safemode.min.datanodes
> = 0
> 2017-08-30 18:02:37,727 [main] INFO blockmanagement.BlockManagerSafeMode
> (BlockManagerSafeMode.java:<init>(164)) - dfs.namenode.safemode.extension = 0
> 2017-08-30 18:02:37,727 [main] INFO blockmanagement.BlockManager
> (BlockManager.java:<init>(546)) - defaultReplication = 3
> 2017-08-30 18:02:37,727 [main] INFO blockmanagement.BlockManager
> (BlockManager.java:<init>(547)) - maxReplication = 512
> 2017-08-30 18:02:37,728 [main] INFO blockmanagement.BlockManager
> (BlockManager.java:<init>(548)) - minReplication = 1
> 2017-08-30 18:02:37,728 [main] INFO blockmanagement.BlockManager
> (BlockManager.java:<init>(549)) - maxReplicationStreams = 2
> 2017-08-30 18:02:37,728 [main] INFO blockmanagement.BlockManager
> (BlockManager.java:<init>(550)) - redundancyRecheckInterval = 3000ms
> 2017-08-30 18:02:37,728 [main] INFO blockmanagement.BlockManager
> (BlockManager.java:<init>(551)) - encryptDataTransfer = false
> 2017-08-30 18:02:37,728 [main] INFO blockmanagement.BlockManager
> (BlockManager.java:<init>(552)) - maxNumBlocksToLog = 1000
> 2017-08-30 18:02:37,729 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
> INodeMap
> 2017-08-30 18:02:37,729 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
> 2017-08-30 18:02:37,729 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(397)) - 1.0% max memory 1.8 GB = 18.2 MB
> 2017-08-30 18:02:37,730 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(402)) - capacity = 2^21 = 2097152
> entries
> 2017-08-30 18:02:37,734 [main] INFO namenode.FSDirectory
> (FSDirectory.java:<init>(278)) - ACLs enabled? false
> 2017-08-30 18:02:37,734 [main] INFO namenode.FSDirectory
> (FSDirectory.java:<init>(282)) - POSIX ACL inheritance enabled? true
> 2017-08-30 18:02:37,734 [main] INFO namenode.FSDirectory
> (FSDirectory.java:<init>(286)) - XAttrs enabled? true
> 2017-08-30 18:02:37,734 [main] INFO namenode.NameNode
> (FSDirectory.java:<init>(350)) - Caching file names occurring more than 10
> times
> 2017-08-30 18:02:37,734 [main] INFO snapshot.SnapshotManager
> (SnapshotManager.java:<init>(105)) - Loaded config captureOpenFiles:
> falseskipCaptureAccessTimeOnlyChange: false
> 2017-08-30 18:02:37,734 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
> cachedBlocks
> 2017-08-30 18:02:37,734 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
> 2017-08-30 18:02:37,735 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(397)) - 0.25% max memory 1.8 GB = 4.6 MB
> 2017-08-30 18:02:37,735 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(402)) - capacity = 2^19 = 524288
> entries
> 2017-08-30 18:02:37,736 [main] INFO metrics.TopMetrics
> (TopMetrics.java:logConf(76)) - NNTop conf:
> dfs.namenode.top.window.num.buckets = 10
> 2017-08-30 18:02:37,736 [main] INFO metrics.TopMetrics
> (TopMetrics.java:logConf(78)) - NNTop conf: dfs.namenode.top.num.users = 10
> 2017-08-30 18:02:37,736 [main] INFO metrics.TopMetrics
> (TopMetrics.java:logConf(80)) - NNTop conf: dfs.namenode.top.windows.minutes
> = 1,5,25
> 2017-08-30 18:02:37,736 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:initRetryCache(968)) - Retry cache on namenode is enabled
> 2017-08-30 18:02:37,737 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:initRetryCache(976)) - Retry cache will use 0.03 of total
> heap and retry cache entry expiry time is 600000 millis
> 2017-08-30 18:02:37,737 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
> NameNodeRetryCache
> 2017-08-30 18:02:37,737 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
> 2017-08-30 18:02:37,737 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(397)) - 0.029999999329447746% max
> memory 1.8 GB = 559.3 KB
> 2017-08-30 18:02:37,737 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(402)) - capacity = 2^16 = 65536
> entries
> 2017-08-30 18:02:37,738 [main] INFO namenode.FSImage
> (FSImage.java:format(164)) - Allocated new BlockPoolId:
> BP-1775344991-172.17.0.2-1504116157738
> 2017-08-30 18:02:37,740 [main] INFO common.Storage
> (NNStorage.java:format(583)) - Storage directory
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/name-0-1
> has been successfully formatted.
> 2017-08-30 18:02:37,741 [main] INFO common.Storage
> (NNStorage.java:format(583)) - Storage directory
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/name-0-2
> has been successfully formatted.
> 2017-08-30 18:02:37,742 [FSImageSaver for
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/name-0-1
> of type IMAGE_AND_EDITS] INFO namenode.FSImageFormatProtobuf
> (FSImageFormatProtobuf.java:save(429)) - Saving image file
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/name-0-1/current/fsimage.ckpt_0000000000000000000
> using no compression
> 2017-08-30 18:02:37,742 [FSImageSaver for
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/name-0-2
> of type IMAGE_AND_EDITS] INFO namenode.FSImageFormatProtobuf
> (FSImageFormatProtobuf.java:save(429)) - Saving image file
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/name-0-2/current/fsimage.ckpt_0000000000000000000
> using no compression
> 2017-08-30 18:02:37,748 [FSImageSaver for
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/name-0-2
> of type IMAGE_AND_EDITS] INFO namenode.FSImageFormatProtobuf
> (FSImageFormatProtobuf.java:save(432)) - Image file
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/name-0-2/current/fsimage.ckpt_0000000000000000000
> of size 335 bytes saved in 0 seconds.
> 2017-08-30 18:02:37,748 [FSImageSaver for
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/name-0-1
> of type IMAGE_AND_EDITS] INFO namenode.FSImageFormatProtobuf
> (FSImageFormatProtobuf.java:save(432)) - Image file
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/name-0-1/current/fsimage.ckpt_0000000000000000000
> of size 335 bytes saved in 0 seconds.
> 2017-08-30 18:02:37,750 [main] INFO namenode.NNStorageRetentionManager
> (NNStorageRetentionManager.java:getImageTxIdToRetain(203)) - Going to retain
> 1 images with txid >= 0
> 2017-08-30 18:02:37,751 [main] INFO namenode.NameNode
> (NameNode.java:createNameNode(1577)) - createNameNode []
> 2017-08-30 18:02:37,753 [main] INFO impl.MetricsConfig
> (MetricsConfig.java:loadFirst(121)) - loaded properties from
> hadoop-metrics2-namenode.properties
> 2017-08-30 18:02:37,754 [main] INFO impl.MetricsSystemImpl
> (MetricsSystemImpl.java:startTimer(374)) - Scheduled Metric snapshot period
> at 1 second(s).
> 2017-08-30 18:02:37,754 [main] INFO impl.MetricsSystemImpl
> (MetricsSystemImpl.java:start(191)) - NameNode metrics system started
> 2017-08-30 18:02:37,755 [main] INFO namenode.NameNode
> (NameNode.java:setClientNamenodeAddress(464)) - fs.defaultFS is
> hdfs://127.0.0.1:0
> 2017-08-30 18:02:37,757
> [org.apache.hadoop.util.JvmPauseMonitor$Monitor@65f2f9b0] INFO
> util.JvmPauseMonitor (JvmPauseMonitor.java:run(188)) - Starting JVM pause
> monitor
> 2017-08-30 18:02:37,758 [main] INFO hdfs.DFSUtil
> (DFSUtil.java:httpServerTemplateForNNAndJN(1512)) - Starting Web-server for
> hdfs at: http://localhost:0
> 2017-08-30 18:02:37,759 [main] INFO server.AuthenticationFilter
> (AuthenticationFilter.java:constructSecretProvider(240)) - Unable to
> initialize FileSignerSecretProvider, falling back to use random secrets.
> 2017-08-30 18:02:37,760 [main] INFO http.HttpRequestLog
> (HttpRequestLog.java:getRequestLog(81)) - Http request log for
> http.requests.namenode is not defined
> 2017-08-30 18:02:37,760 [main] INFO http.HttpServer2
> (HttpServer2.java:addGlobalFilter(921)) - Added global filter 'safety'
> (class=org.apache.hadoop.http.HttpServer2$QuotingInputFilter)
> 2017-08-30 18:02:37,761 [main] INFO http.HttpServer2
> (HttpServer2.java:addFilter(894)) - Added filter static_user_filter
> (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
> context hdfs
> 2017-08-30 18:02:37,761 [main] INFO http.HttpServer2
> (HttpServer2.java:addFilter(904)) - Added filter static_user_filter
> (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
> context static
> 2017-08-30 18:02:37,761 [main] INFO http.HttpServer2
> (HttpServer2.java:addFilter(904)) - Added filter static_user_filter
> (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
> context logs
> 2017-08-30 18:02:37,762 [main] INFO http.HttpServer2
> (NameNodeHttpServer.java:initWebHdfs(98)) - Added filter
> 'org.apache.hadoop.hdfs.web.AuthFilter'
> (class=org.apache.hadoop.hdfs.web.AuthFilter)
> 2017-08-30 18:02:37,762 [main] INFO http.HttpServer2
> (HttpServer2.java:addJerseyResourcePackage(779)) - addJerseyResourcePackage:
> packageName=org.apache.hadoop.hdfs.server.namenode.web.resources;org.apache.hadoop.hdfs.web.resources,
> pathSpec=/webhdfs/v1/*
> 2017-08-30 18:02:37,762 [main] INFO http.HttpServer2
> (HttpServer2.java:bindListener(1121)) - Jetty bound to port 35619
> 2017-08-30 18:02:37,763 [main] INFO server.Server (Server.java:doStart(346))
> - jetty-9.3.19.v20170502
> 2017-08-30 18:02:37,764 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStart(781)) - Started
> o.e.j.s.ServletContextHandler@46c3a14d{/logs,file:///testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/log/,AVAILABLE}
> 2017-08-30 18:02:37,765 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStart(781)) - Started
> o.e.j.s.ServletContextHandler@5e8cda75{/static,file:///testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test-classes/webapps/static/,AVAILABLE}
> 2017-08-30 18:02:37,771 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStart(781)) - Started
> o.e.j.w.WebAppContext@5633dafd{/,file:///testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test-classes/webapps/hdfs/,AVAILABLE}{/hdfs}
> 2017-08-30 18:02:37,772 [main] INFO server.AbstractConnector
> (AbstractConnector.java:doStart(278)) - Started
> ServerConnector@5d5160e6{HTTP/1.1,[http/1.1]}{localhost:35619}
> 2017-08-30 18:02:37,772 [main] INFO server.Server (Server.java:doStart(414))
> - Started @37288ms
> 2017-08-30 18:02:37,775 [main] INFO namenode.FSEditLog
> (FSEditLog.java:newInstance(224)) - Edit logging is async:false
> 2017-08-30 18:02:37,775 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:<init>(742)) - KeyProvider: null
> 2017-08-30 18:02:37,775 [main] INFO namenode.FSNamesystem
> (FSNamesystemLock.java:<init>(120)) - fsLock is fair: true
> 2017-08-30 18:02:37,775 [main] INFO namenode.FSNamesystem
> (FSNamesystemLock.java:<init>(136)) - Detailed lock hold time metrics
> enabled: false
> 2017-08-30 18:02:37,776 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:<init>(763)) - fsOwner = jenkins (auth:SIMPLE)
> 2017-08-30 18:02:37,776 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:<init>(764)) - supergroup = supergroup
> 2017-08-30 18:02:37,776 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:<init>(765)) - isPermissionEnabled = true
> 2017-08-30 18:02:37,776 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:<init>(776)) - HA Enabled: false
> 2017-08-30 18:02:37,777 [main] INFO common.Util
> (Util.java:isDiskStatsEnabled(395)) -
> dfs.datanode.fileio.profiling.sampling.percentage set to 0. Disabling file IO
> profiling
> 2017-08-30 18:02:37,777 [main] INFO blockmanagement.DatanodeManager
> (DatanodeManager.java:<init>(301)) - dfs.block.invalidate.limit:
> configured=1000, counted=60, effected=1000
> 2017-08-30 18:02:37,777 [main] INFO blockmanagement.DatanodeManager
> (DatanodeManager.java:<init>(309)) -
> dfs.namenode.datanode.registration.ip-hostname-check=true
> 2017-08-30 18:02:37,777 [main] INFO blockmanagement.BlockManager
> (InvalidateBlocks.java:printBlockDeletionTime(76)) -
> dfs.namenode.startup.delay.block.deletion.sec is set to 000:00:00:00.000
> 2017-08-30 18:02:37,778 [main] INFO blockmanagement.BlockManager
> (InvalidateBlocks.java:printBlockDeletionTime(82)) - The block deletion will
> start around 2017 Aug 30 18:02:37
> 2017-08-30 18:02:37,778 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
> BlocksMap
> 2017-08-30 18:02:37,778 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
> 2017-08-30 18:02:37,778 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(397)) - 2.0% max memory 1.8 GB = 36.4 MB
> 2017-08-30 18:02:37,779 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(402)) - capacity = 2^22 = 4194304
> entries
> 2017-08-30 18:02:37,784 [main] INFO blockmanagement.BlockManager
> (BlockManager.java:createBlockTokenSecretManager(560)) -
> dfs.block.access.token.enable = false
> 2017-08-30 18:02:37,785 [main] INFO Configuration.deprecation
> (Configuration.java:logDeprecation(1285)) - No unit for
> dfs.namenode.safemode.extension(0) assuming MILLISECONDS
> 2017-08-30 18:02:37,785 [main] INFO blockmanagement.BlockManagerSafeMode
> (BlockManagerSafeMode.java:<init>(161)) - dfs.namenode.safemode.threshold-pct
> = 0.9990000128746033
> 2017-08-30 18:02:37,785 [main] INFO blockmanagement.BlockManagerSafeMode
> (BlockManagerSafeMode.java:<init>(162)) - dfs.namenode.safemode.min.datanodes
> = 0
> 2017-08-30 18:02:37,785 [main] INFO blockmanagement.BlockManagerSafeMode
> (BlockManagerSafeMode.java:<init>(164)) - dfs.namenode.safemode.extension = 0
> 2017-08-30 18:02:37,785 [main] INFO blockmanagement.BlockManager
> (BlockManager.java:<init>(546)) - defaultReplication = 3
> 2017-08-30 18:02:37,785 [main] INFO blockmanagement.BlockManager
> (BlockManager.java:<init>(547)) - maxReplication = 512
> 2017-08-30 18:02:37,786 [main] INFO blockmanagement.BlockManager
> (BlockManager.java:<init>(548)) - minReplication = 1
> 2017-08-30 18:02:37,786 [main] INFO blockmanagement.BlockManager
> (BlockManager.java:<init>(549)) - maxReplicationStreams = 2
> 2017-08-30 18:02:37,786 [main] INFO blockmanagement.BlockManager
> (BlockManager.java:<init>(550)) - redundancyRecheckInterval = 3000ms
> 2017-08-30 18:02:37,786 [main] INFO blockmanagement.BlockManager
> (BlockManager.java:<init>(551)) - encryptDataTransfer = false
> 2017-08-30 18:02:37,786 [main] INFO blockmanagement.BlockManager
> (BlockManager.java:<init>(552)) - maxNumBlocksToLog = 1000
> 2017-08-30 18:02:37,786 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
> INodeMap
> 2017-08-30 18:02:37,787 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
> 2017-08-30 18:02:37,787 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(397)) - 1.0% max memory 1.8 GB = 18.2 MB
> 2017-08-30 18:02:37,787 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(402)) - capacity = 2^21 = 2097152
> entries
> 2017-08-30 18:02:37,790 [main] INFO namenode.FSDirectory
> (FSDirectory.java:<init>(278)) - ACLs enabled? false
> 2017-08-30 18:02:37,791 [main] INFO namenode.FSDirectory
> (FSDirectory.java:<init>(282)) - POSIX ACL inheritance enabled? true
> 2017-08-30 18:02:37,791 [main] INFO namenode.FSDirectory
> (FSDirectory.java:<init>(286)) - XAttrs enabled? true
> 2017-08-30 18:02:37,791 [main] INFO namenode.NameNode
> (FSDirectory.java:<init>(350)) - Caching file names occurring more than 10
> times
> 2017-08-30 18:02:37,791 [main] INFO snapshot.SnapshotManager
> (SnapshotManager.java:<init>(105)) - Loaded config captureOpenFiles:
> falseskipCaptureAccessTimeOnlyChange: false
> 2017-08-30 18:02:37,791 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
> cachedBlocks
> 2017-08-30 18:02:37,791 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
> 2017-08-30 18:02:37,792 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(397)) - 0.25% max memory 1.8 GB = 4.6 MB
> 2017-08-30 18:02:37,792 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(402)) - capacity = 2^19 = 524288
> entries
> 2017-08-30 18:02:37,793 [main] INFO metrics.TopMetrics
> (TopMetrics.java:logConf(76)) - NNTop conf:
> dfs.namenode.top.window.num.buckets = 10
> 2017-08-30 18:02:37,793 [main] INFO metrics.TopMetrics
> (TopMetrics.java:logConf(78)) - NNTop conf: dfs.namenode.top.num.users = 10
> 2017-08-30 18:02:37,793 [main] INFO metrics.TopMetrics
> (TopMetrics.java:logConf(80)) - NNTop conf: dfs.namenode.top.windows.minutes
> = 1,5,25
> 2017-08-30 18:02:37,793 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:initRetryCache(968)) - Retry cache on namenode is enabled
> 2017-08-30 18:02:37,793 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:initRetryCache(976)) - Retry cache will use 0.03 of total
> heap and retry cache entry expiry time is 600000 millis
> 2017-08-30 18:02:37,793 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
> NameNodeRetryCache
> 2017-08-30 18:02:37,794 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
> 2017-08-30 18:02:37,794 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(397)) - 0.029999999329447746% max
> memory 1.8 GB = 559.3 KB
> 2017-08-30 18:02:37,794 [main] INFO util.GSet
> (LightWeightGSet.java:computeCapacity(402)) - capacity = 2^16 = 65536
> entries
> 2017-08-30 18:02:37,831 [main] INFO common.Storage
> (Storage.java:tryLock(847)) - Lock on
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/name-0-1/in_use.lock
> acquired by nodename 26462@0c74973bd755
> 2017-08-30 18:02:37,833 [main] INFO common.Storage
> (Storage.java:tryLock(847)) - Lock on
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/name-0-2/in_use.lock
> acquired by nodename 26462@0c74973bd755
> 2017-08-30 18:02:37,834 [main] INFO namenode.FileJournalManager
> (FileJournalManager.java:recoverUnfinalizedSegments(396)) - Recovering
> unfinalized segments in
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/name-0-1/current
> 2017-08-30 18:02:37,834 [main] INFO namenode.FileJournalManager
> (FileJournalManager.java:recoverUnfinalizedSegments(396)) - Recovering
> unfinalized segments in
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/name-0-2/current
> 2017-08-30 18:02:37,834 [main] INFO namenode.FSImage
> (FSImage.java:loadFSImage(712)) - No edit log streams selected.
> 2017-08-30 18:02:37,835 [main] INFO namenode.FSImage
> (FSImage.java:loadFSImageFile(775)) - Planning to load image:
> FSImageFile(file=/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/name-0-1/current/fsimage_0000000000000000000,
> cpktTxId=0000000000000000000)
> 2017-08-30 18:02:37,835 [main] INFO namenode.FSImageFormatPBINode
> (FSImageFormatPBINode.java:loadINodeSection(266)) - Loading 1 INodes.
> 2017-08-30 18:02:37,836 [main] INFO namenode.FSImageFormatProtobuf
> (FSImageFormatProtobuf.java:load(185)) - Loaded FSImage in 0 seconds.
> 2017-08-30 18:02:37,836 [main] INFO namenode.FSImage
> (FSImage.java:loadFSImage(941)) - Loaded image for txid 0 from
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/name-0-1/current/fsimage_0000000000000000000
> 2017-08-30 18:02:37,836 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:loadFSImage(1080)) - Need to save fs image? false
> (staleImage=false, haEnabled=false, isRollingUpgrade=false)
> 2017-08-30 18:02:37,836 [main] INFO namenode.FSEditLog
> (FSEditLog.java:startLogSegment(1324)) - Starting log segment at 1
> 2017-08-30 18:02:37,841 [main] INFO namenode.NameCache
> (NameCache.java:initialized(143)) - initialized with 0 entries 0 lookups
> 2017-08-30 18:02:37,841 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:loadFromDisk(714)) - Finished loading FSImage in 46 msecs
> 2017-08-30 18:02:37,841 [main] INFO namenode.NameNode
> (NameNodeRpcServer.java:<init>(439)) - RPC server is binding to localhost:0
> 2017-08-30 18:02:37,842 [main] INFO ipc.CallQueueManager
> (CallQueueManager.java:<init>(84)) - Using callQueue: class
> java.util.concurrent.LinkedBlockingQueue queueCapacity: 1000 scheduler: class
> org.apache.hadoop.ipc.DefaultRpcScheduler
> 2017-08-30 18:02:37,842 [Socket Reader #1 for port 47551] INFO ipc.Server
> (Server.java:run(1067)) - Starting Socket Reader #1 for port 47551
> 2017-08-30 18:02:37,847 [main] INFO namenode.NameNode
> (NameNode.java:initialize(737)) - Clients are to use localhost:47551 to
> access this namenode/service.
> 2017-08-30 18:02:37,847 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:registerMBean(4811)) - Registered FSNamesystemState,
> ReplicatedBlocksState and ECBlockGroupsState MBeans.
> 2017-08-30 18:02:37,858 [main] INFO namenode.LeaseManager
> (LeaseManager.java:getNumUnderConstructionBlocks(158)) - Number of blocks
> under construction: 0
> 2017-08-30 18:02:37,859 [main] INFO blockmanagement.BlockManager
> (BlockManager.java:initializeReplQueues(4650)) - initializing replication
> queues
> 2017-08-30 18:02:37,860 [main] INFO hdfs.StateChange
> (BlockManagerSafeMode.java:leaveSafeMode(396)) - STATE* Leaving safe mode
> after 0 secs
> 2017-08-30 18:02:37,860 [main] INFO hdfs.StateChange
> (BlockManagerSafeMode.java:leaveSafeMode(402)) - STATE* Network topology has
> 0 racks and 0 datanodes
> 2017-08-30 18:02:37,860 [main] INFO hdfs.StateChange
> (BlockManagerSafeMode.java:leaveSafeMode(404)) - STATE* UnderReplicatedBlocks
> has 0 blocks
> 2017-08-30 18:02:37,866 [Reconstruction Queue Initializer] INFO
> blockmanagement.BlockManager
> (BlockManager.java:processMisReplicatesAsync(3355)) - Total number of blocks
> = 0
> 2017-08-30 18:02:37,867 [Reconstruction Queue Initializer] INFO
> blockmanagement.BlockManager
> (BlockManager.java:processMisReplicatesAsync(3356)) - Number of invalid
> blocks = 0
> 2017-08-30 18:02:37,867 [Reconstruction Queue Initializer] INFO
> blockmanagement.BlockManager
> (BlockManager.java:processMisReplicatesAsync(3357)) - Number of
> under-replicated blocks = 0
> 2017-08-30 18:02:37,867 [Reconstruction Queue Initializer] INFO
> blockmanagement.BlockManager
> (BlockManager.java:processMisReplicatesAsync(3358)) - Number of
> over-replicated blocks = 0
> 2017-08-30 18:02:37,867 [Reconstruction Queue Initializer] INFO
> blockmanagement.BlockManager
> (BlockManager.java:processMisReplicatesAsync(3360)) - Number of blocks being
> written = 0
> 2017-08-30 18:02:37,867 [Reconstruction Queue Initializer] INFO
> hdfs.StateChange (BlockManager.java:processMisReplicatesAsync(3363)) - STATE*
> Replication Queue initialization scan for invalid, over- and under-replicated
> blocks completed in 8 msec
> 2017-08-30 18:02:37,869 [IPC Server Responder] INFO ipc.Server
> (Server.java:run(1307)) - IPC Server Responder: starting
> 2017-08-30 18:02:37,869 [IPC Server listener on 47551] INFO ipc.Server
> (Server.java:run(1146)) - IPC Server listener on 47551: starting
> 2017-08-30 18:02:37,872 [main] INFO namenode.NameNode
> (NameNode.java:startCommonServices(830)) - NameNode RPC up at:
> localhost/127.0.0.1:47551
> 2017-08-30 18:02:37,873 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:startActiveServices(1192)) - Starting services required
> for active state
> 2017-08-30 18:02:37,873 [main] INFO namenode.FSDirectory
> (FSDirectory.java:updateCountForQuota(706)) - Initializing quota with 4
> thread(s)
> 2017-08-30 18:02:37,873 [main] INFO namenode.FSDirectory
> (FSDirectory.java:updateCountForQuota(715)) - Quota initialization completed
> in 0 milliseconds
> name space=1
> storage space=0
> storage types=RAM_DISK=0, SSD=0, DISK=0, ARCHIVE=0
> 2017-08-30 18:02:37,875 [CacheReplicationMonitor(1864849826)] INFO
> blockmanagement.CacheReplicationMonitor
> (CacheReplicationMonitor.java:run(160)) - Starting CacheReplicationMonitor
> with interval 30000 milliseconds
> 2017-08-30 18:02:37,879 [main] INFO hdfs.MiniDFSCluster
> (MiniDFSCluster.java:startDataNodes(1591)) - Starting DataNode 0 with
> dfs.datanode.data.dir:
> [DISK]file:/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1,[DISK]file:/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2
> 2017-08-30 18:02:37,879 [main] INFO checker.ThrottledAsyncChecker
> (ThrottledAsyncChecker.java:schedule(122)) - Scheduling a check for
> [DISK]file:/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1
> 2017-08-30 18:02:37,880 [main] INFO checker.ThrottledAsyncChecker
> (ThrottledAsyncChecker.java:schedule(122)) - Scheduling a check for
> [DISK]file:/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2
> 2017-08-30 18:02:37,887 [main] INFO impl.MetricsSystemImpl
> (MetricsSystemImpl.java:init(158)) - DataNode metrics system started (again)
> 2017-08-30 18:02:37,887 [main] INFO common.Util
> (Util.java:isDiskStatsEnabled(395)) -
> dfs.datanode.fileio.profiling.sampling.percentage set to 0. Disabling file IO
> profiling
> 2017-08-30 18:02:37,887 [main] INFO datanode.BlockScanner
> (BlockScanner.java:<init>(184)) - Initialized block scanner with
> targetBytesPerSec 1048576
> 2017-08-30 18:02:37,888 [main] INFO datanode.DataNode
> (DataNode.java:<init>(496)) - Configured hostname is 127.0.0.1
> 2017-08-30 18:02:37,888 [main] INFO common.Util
> (Util.java:isDiskStatsEnabled(395)) -
> dfs.datanode.fileio.profiling.sampling.percentage set to 0. Disabling file IO
> profiling
> 2017-08-30 18:02:37,888 [main] INFO datanode.DataNode
> (DataNode.java:startDataNode(1385)) - Starting DataNode with maxLockedMemory
> = 0
> 2017-08-30 18:02:37,888 [main] INFO datanode.DataNode
> (DataNode.java:initDataXceiver(1142)) - Opened streaming server at
> /127.0.0.1:46794
> 2017-08-30 18:02:37,889 [main] INFO datanode.DataNode
> (DataXceiverServer.java:<init>(78)) - Balancing bandwidth is 10485760 bytes/s
> 2017-08-30 18:02:37,889 [main] INFO datanode.DataNode
> (DataXceiverServer.java:<init>(79)) - Number threads for balancing is 50
> 2017-08-30 18:02:37,892 [main] INFO server.AuthenticationFilter
> (AuthenticationFilter.java:constructSecretProvider(240)) - Unable to
> initialize FileSignerSecretProvider, falling back to use random secrets.
> 2017-08-30 18:02:37,892 [main] INFO http.HttpRequestLog
> (HttpRequestLog.java:getRequestLog(81)) - Http request log for
> http.requests.datanode is not defined
> 2017-08-30 18:02:37,893 [main] INFO http.HttpServer2
> (HttpServer2.java:addGlobalFilter(921)) - Added global filter 'safety'
> (class=org.apache.hadoop.http.HttpServer2$QuotingInputFilter)
> 2017-08-30 18:02:37,893 [main] INFO http.HttpServer2
> (HttpServer2.java:addFilter(894)) - Added filter static_user_filter
> (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
> context datanode
> 2017-08-30 18:02:37,894 [main] INFO http.HttpServer2
> (HttpServer2.java:addFilter(904)) - Added filter static_user_filter
> (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
> context static
> 2017-08-30 18:02:37,894 [main] INFO http.HttpServer2
> (HttpServer2.java:addFilter(904)) - Added filter static_user_filter
> (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
> context logs
> 2017-08-30 18:02:37,894 [main] INFO http.HttpServer2
> (HttpServer2.java:bindListener(1121)) - Jetty bound to port 46189
> 2017-08-30 18:02:37,895 [main] INFO server.Server (Server.java:doStart(346))
> - jetty-9.3.19.v20170502
> 2017-08-30 18:02:37,897 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStart(781)) - Started
> o.e.j.s.ServletContextHandler@4e1ce44{/logs,file:///testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/log/,AVAILABLE}
> 2017-08-30 18:02:37,898 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStart(781)) - Started
> o.e.j.s.ServletContextHandler@7a7cc52c{/static,file:///testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test-classes/webapps/static/,AVAILABLE}
> 2017-08-30 18:02:37,903 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStart(781)) - Started
> o.e.j.w.WebAppContext@29eda4f8{/,file:///testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test-classes/webapps/datanode/,AVAILABLE}{/datanode}
> 2017-08-30 18:02:37,904 [main] INFO server.AbstractConnector
> (AbstractConnector.java:doStart(278)) - Started
> ServerConnector@1b9776f5{HTTP/1.1,[http/1.1]}{localhost:46189}
> 2017-08-30 18:02:37,905 [main] INFO server.Server (Server.java:doStart(414))
> - Started @37420ms
> 2017-08-30 18:02:37,911 [main] INFO web.DatanodeHttpServer
> (DatanodeHttpServer.java:start(239)) - Listening HTTP traffic on
> /127.0.0.1:52625
> 2017-08-30 18:02:37,911
> [org.apache.hadoop.util.JvmPauseMonitor$Monitor@79d9214d] INFO
> util.JvmPauseMonitor (JvmPauseMonitor.java:run(188)) - Starting JVM pause
> monitor
> 2017-08-30 18:02:37,911 [main] INFO datanode.DataNode
> (DataNode.java:startDataNode(1412)) - dnUserName = jenkins
> 2017-08-30 18:02:37,911 [main] INFO datanode.DataNode
> (DataNode.java:startDataNode(1413)) - supergroup = supergroup
> 2017-08-30 18:02:37,912 [main] INFO ipc.CallQueueManager
> (CallQueueManager.java:<init>(84)) - Using callQueue: class
> java.util.concurrent.LinkedBlockingQueue queueCapacity: 1000 scheduler: class
> org.apache.hadoop.ipc.DefaultRpcScheduler
> 2017-08-30 18:02:37,912 [Socket Reader #1 for port 58248] INFO ipc.Server
> (Server.java:run(1067)) - Starting Socket Reader #1 for port 58248
> 2017-08-30 18:02:37,915 [main] INFO datanode.DataNode
> (DataNode.java:initIpcServer(1029)) - Opened IPC server at /127.0.0.1:58248
> 2017-08-30 18:02:37,916 [main] INFO datanode.DataNode
> (BlockPoolManager.java:refreshNamenodes(149)) - Refresh request received for
> nameservices: null
> 2017-08-30 18:02:37,917 [main] INFO datanode.DataNode
> (BlockPoolManager.java:doRefreshNamenodes(198)) - Starting BPOfferServices
> for nameservices: <default>
> 2017-08-30 18:02:37,917 [Thread-997] INFO datanode.DataNode
> (BPServiceActor.java:run(809)) - Block pool <registering> (Datanode Uuid
> unassigned) service to localhost/127.0.0.1:47551 starting to offer service
> 2017-08-30 18:02:37,918 [IPC Server Responder] INFO ipc.Server
> (Server.java:run(1307)) - IPC Server Responder: starting
> 2017-08-30 18:02:37,919 [IPC Server listener on 58248] INFO ipc.Server
> (Server.java:run(1146)) - IPC Server listener on 58248: starting
> 2017-08-30 18:02:37,922 [main] INFO hdfs.MiniDFSCluster
> (MiniDFSCluster.java:startDataNodes(1591)) - Starting DataNode 1 with
> dfs.datanode.data.dir:
> [DISK]file:/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data3,[DISK]file:/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data4
> 2017-08-30 18:02:37,923 [Thread-997] INFO datanode.DataNode
> (BPOfferService.java:verifyAndSetNamespaceInfo(364)) - Acknowledging ACTIVE
> Namenode during handshakeBlock pool <registering> (Datanode Uuid unassigned)
> service to localhost/127.0.0.1:47551
> 2017-08-30 18:02:37,924 [Thread-997] INFO common.Storage
> (DataStorage.java:getParallelVolumeLoadThreadsNum(346)) - Using 2 threads to
> upgrade data directories (dfs.datanode.parallel.volumes.load.threads.num=2,
> dataDirs=2)
> 2017-08-30 18:02:37,925 [main] INFO checker.ThrottledAsyncChecker
> (ThrottledAsyncChecker.java:schedule(122)) - Scheduling a check for
> [DISK]file:/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data3
> 2017-08-30 18:02:37,925 [main] INFO checker.ThrottledAsyncChecker
> (ThrottledAsyncChecker.java:schedule(122)) - Scheduling a check for
> [DISK]file:/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data4
> 2017-08-30 18:02:37,925 [Thread-997] INFO common.Storage
> (Storage.java:tryLock(847)) - Lock on
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1/in_use.lock
> acquired by nodename 26462@0c74973bd755
> 2017-08-30 18:02:37,925 [Thread-997] INFO common.Storage
> (DataStorage.java:loadStorageDirectory(273)) - Storage directory with
> location
> [DISK]file:/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1
> is not formatted for namespace 785578744. Formatting...
> 2017-08-30 18:02:37,925 [Thread-997] INFO common.Storage
> (DataStorage.java:createStorageID(150)) - Generated new storageID
> DS-c7f21b9d-2106-4d12-bb20-c414e1397d77 for directory
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1
> 2017-08-30 18:02:37,927 [Thread-997] INFO common.Storage
> (Storage.java:tryLock(847)) - Lock on
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2/in_use.lock
> acquired by nodename 26462@0c74973bd755
> 2017-08-30 18:02:37,927 [Thread-997] INFO common.Storage
> (DataStorage.java:loadStorageDirectory(273)) - Storage directory with
> location
> [DISK]file:/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2
> is not formatted for namespace 785578744. Formatting...
> 2017-08-30 18:02:37,928 [Thread-997] INFO common.Storage
> (DataStorage.java:createStorageID(150)) - Generated new storageID
> DS-230ffa8a-d07d-4ac0-86e2-9acc7403dc9d for directory
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2
> 2017-08-30 18:02:37,934 [main] INFO impl.MetricsSystemImpl
> (MetricsSystemImpl.java:init(158)) - DataNode metrics system started (again)
> 2017-08-30 18:02:37,934 [main] INFO common.Util
> (Util.java:isDiskStatsEnabled(395)) -
> dfs.datanode.fileio.profiling.sampling.percentage set to 0. Disabling file IO
> profiling
> 2017-08-30 18:02:37,935 [main] INFO datanode.BlockScanner
> (BlockScanner.java:<init>(184)) - Initialized block scanner with
> targetBytesPerSec 1048576
> 2017-08-30 18:02:37,935 [main] INFO datanode.DataNode
> (DataNode.java:<init>(496)) - Configured hostname is 127.0.0.1
> 2017-08-30 18:02:37,935 [main] INFO common.Util
> (Util.java:isDiskStatsEnabled(395)) -
> dfs.datanode.fileio.profiling.sampling.percentage set to 0. Disabling file IO
> profiling
> 2017-08-30 18:02:37,936 [main] INFO datanode.DataNode
> (DataNode.java:startDataNode(1385)) - Starting DataNode with maxLockedMemory
> = 0
> 2017-08-30 18:02:37,936 [main] INFO datanode.DataNode
> (DataNode.java:initDataXceiver(1142)) - Opened streaming server at
> /127.0.0.1:51925
> 2017-08-30 18:02:37,936 [main] INFO datanode.DataNode
> (DataXceiverServer.java:<init>(78)) - Balancing bandwidth is 10485760 bytes/s
> 2017-08-30 18:02:37,937 [main] INFO datanode.DataNode
> (DataXceiverServer.java:<init>(79)) - Number threads for balancing is 50
> 2017-08-30 18:02:37,939 [main] INFO server.AuthenticationFilter
> (AuthenticationFilter.java:constructSecretProvider(240)) - Unable to
> initialize FileSignerSecretProvider, falling back to use random secrets.
> 2017-08-30 18:02:37,939 [main] INFO http.HttpRequestLog
> (HttpRequestLog.java:getRequestLog(81)) - Http request log for
> http.requests.datanode is not defined
> 2017-08-30 18:02:37,940 [main] INFO http.HttpServer2
> (HttpServer2.java:addGlobalFilter(921)) - Added global filter 'safety'
> (class=org.apache.hadoop.http.HttpServer2$QuotingInputFilter)
> 2017-08-30 18:02:37,941 [Thread-997] INFO common.Storage
> (BlockPoolSliceStorage.java:recoverTransitionRead(252)) - Analyzing storage
> directories for bpid BP-1775344991-172.17.0.2-1504116157738
> 2017-08-30 18:02:37,941 [main] INFO http.HttpServer2
> (HttpServer2.java:addFilter(894)) - Added filter static_user_filter
> (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
> context datanode
> 2017-08-30 18:02:37,941 [Thread-997] INFO common.Storage
> (Storage.java:lock(806)) - Locking is disabled for
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1/current/BP-1775344991-172.17.0.2-1504116157738
> 2017-08-30 18:02:37,941 [main] INFO http.HttpServer2
> (HttpServer2.java:addFilter(904)) - Added filter static_user_filter
> (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
> context logs
> 2017-08-30 18:02:37,941 [Thread-997] INFO common.Storage
> (BlockPoolSliceStorage.java:loadStorageDirectory(168)) - Block pool storage
> directory for location
> [DISK]file:/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1
> and block pool id BP-1775344991-172.17.0.2-1504116157738 is not formatted
> for BP-1775344991-172.17.0.2-1504116157738. Formatting ...
> 2017-08-30 18:02:37,941 [Thread-997] INFO common.Storage
> (BlockPoolSliceStorage.java:format(280)) - Formatting block pool
> BP-1775344991-172.17.0.2-1504116157738 directory
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1/current/BP-1775344991-172.17.0.2-1504116157738/current
> 2017-08-30 18:02:37,941 [main] INFO http.HttpServer2
> (HttpServer2.java:addFilter(904)) - Added filter static_user_filter
> (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
> context static
> 2017-08-30 18:02:37,942 [main] INFO http.HttpServer2
> (HttpServer2.java:bindListener(1121)) - Jetty bound to port 55765
> 2017-08-30 18:02:37,942 [main] INFO server.Server (Server.java:doStart(346))
> - jetty-9.3.19.v20170502
> 2017-08-30 18:02:37,945 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStart(781)) - Started
> o.e.j.s.ServletContextHandler@6631cb64{/logs,file:///testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/log/,AVAILABLE}
> 2017-08-30 18:02:37,945 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStart(781)) - Started
> o.e.j.s.ServletContextHandler@481e91b6{/static,file:///testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test-classes/webapps/static/,AVAILABLE}
> 2017-08-30 18:02:37,951 [Thread-997] INFO common.Storage
> (BlockPoolSliceStorage.java:recoverTransitionRead(252)) - Analyzing storage
> directories for bpid BP-1775344991-172.17.0.2-1504116157738
> 2017-08-30 18:02:37,952 [Thread-997] INFO common.Storage
> (Storage.java:lock(806)) - Locking is disabled for
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2/current/BP-1775344991-172.17.0.2-1504116157738
> 2017-08-30 18:02:37,952 [Thread-997] INFO common.Storage
> (BlockPoolSliceStorage.java:loadStorageDirectory(168)) - Block pool storage
> directory for location
> [DISK]file:/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2
> and block pool id BP-1775344991-172.17.0.2-1504116157738 is not formatted
> for BP-1775344991-172.17.0.2-1504116157738. Formatting ...
> 2017-08-30 18:02:37,952 [Thread-997] INFO common.Storage
> (BlockPoolSliceStorage.java:format(280)) - Formatting block pool
> BP-1775344991-172.17.0.2-1504116157738 directory
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2/current/BP-1775344991-172.17.0.2-1504116157738/current
> 2017-08-30 18:02:37,953 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStart(781)) - Started
> o.e.j.w.WebAppContext@42b28ff1{/,file:///testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test-classes/webapps/datanode/,AVAILABLE}{/datanode}
> 2017-08-30 18:02:37,954 [Thread-997] INFO datanode.DataNode
> (DataNode.java:initStorage(1693)) - Setting up storage:
> nsid=785578744;bpid=BP-1775344991-172.17.0.2-1504116157738;lv=-57;nsInfo=lv=-64;cid=testClusterID;nsid=785578744;c=1504116157738;bpid=BP-1775344991-172.17.0.2-1504116157738;dnuuid=null
> 2017-08-30 18:02:37,954 [main] INFO server.AbstractConnector
> (AbstractConnector.java:doStart(278)) - Started
> ServerConnector@36061cf3{HTTP/1.1,[http/1.1]}{localhost:55765}
> 2017-08-30 18:02:37,954 [main] INFO server.Server (Server.java:doStart(414))
> - Started @37470ms
> 2017-08-30 18:02:37,955 [Thread-997] INFO datanode.DataNode
> (DataNode.java:checkDatanodeUuid(1517)) - Generated and persisted new
> Datanode UUID d7ee1847-d046-47ea-9a05-7fd25bcb1e86
> 2017-08-30 18:02:37,959 [Thread-997] INFO impl.FsDatasetImpl
> (FsVolumeList.java:addVolume(306)) - Added new volume:
> DS-c7f21b9d-2106-4d12-bb20-c414e1397d77
> 2017-08-30 18:02:37,962 [Thread-997] INFO impl.FsDatasetImpl
> (FsDatasetImpl.java:addVolume(435)) - Added volume -
> [DISK]file:/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1,
> StorageType: DISK
> 2017-08-30 18:02:37,963 [Thread-997] INFO impl.FsDatasetImpl
> (FsVolumeList.java:addVolume(306)) - Added new volume:
> DS-230ffa8a-d07d-4ac0-86e2-9acc7403dc9d
> 2017-08-30 18:02:37,964 [Thread-997] INFO impl.FsDatasetImpl
> (FsDatasetImpl.java:addVolume(435)) - Added volume -
> [DISK]file:/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2,
> StorageType: DISK
> 2017-08-30 18:02:37,964 [Thread-997] INFO impl.FsDatasetImpl
> (FsDatasetImpl.java:registerMBean(2178)) - Registered FSDatasetState MBean
> 2017-08-30 18:02:37,965 [Thread-997] INFO checker.ThrottledAsyncChecker
> (ThrottledAsyncChecker.java:schedule(122)) - Scheduling a check for
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1
> 2017-08-30 18:02:37,967 [Thread-997] INFO checker.DatasetVolumeChecker
> (DatasetVolumeChecker.java:checkAllVolumes(210)) - Scheduled health check for
> volume
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1
> 2017-08-30 18:02:37,967 [main] INFO web.DatanodeHttpServer
> (DatanodeHttpServer.java:start(239)) - Listening HTTP traffic on
> /127.0.0.1:42070
> 2017-08-30 18:02:37,967 [Thread-997] INFO checker.ThrottledAsyncChecker
> (ThrottledAsyncChecker.java:schedule(122)) - Scheduling a check for
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2
> 2017-08-30 18:02:37,967 [Thread-997] INFO checker.DatasetVolumeChecker
> (DatasetVolumeChecker.java:checkAllVolumes(210)) - Scheduled health check for
> volume
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2
> 2017-08-30 18:02:37,968 [main] INFO datanode.DataNode
> (DataNode.java:startDataNode(1412)) - dnUserName = jenkins
> 2017-08-30 18:02:37,968 [main] INFO datanode.DataNode
> (DataNode.java:startDataNode(1413)) - supergroup = supergroup
> 2017-08-30 18:02:37,968
> [org.apache.hadoop.util.JvmPauseMonitor$Monitor@76889e60] INFO
> util.JvmPauseMonitor (JvmPauseMonitor.java:run(188)) - Starting JVM pause
> monitor
> 2017-08-30 18:02:37,968 [Thread-997] INFO impl.FsDatasetImpl
> (FsDatasetImpl.java:addBlockPool(2664)) - Adding block pool
> BP-1775344991-172.17.0.2-1504116157738
> 2017-08-30 18:02:37,969 [main] INFO ipc.CallQueueManager
> (CallQueueManager.java:<init>(84)) - Using callQueue: class
> java.util.concurrent.LinkedBlockingQueue queueCapacity: 1000 scheduler: class
> org.apache.hadoop.ipc.DefaultRpcScheduler
> 2017-08-30 18:02:37,969 [Thread-1025] INFO impl.FsDatasetImpl
> (FsVolumeList.java:run(409)) - Scanning block pool
> BP-1775344991-172.17.0.2-1504116157738 on volume
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1...
> 2017-08-30 18:02:37,969 [Thread-1026] INFO impl.FsDatasetImpl
> (FsVolumeList.java:run(409)) - Scanning block pool
> BP-1775344991-172.17.0.2-1504116157738 on volume
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2...
> 2017-08-30 18:02:37,969 [Socket Reader #1 for port 50140] INFO ipc.Server
> (Server.java:run(1067)) - Starting Socket Reader #1 for port 50140
> 2017-08-30 18:02:37,975 [Thread-1026] INFO impl.FsDatasetImpl
> (FsVolumeList.java:run(414)) - Time taken to scan block pool
> BP-1775344991-172.17.0.2-1504116157738 on
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2:
> 7ms
> 2017-08-30 18:02:37,977 [main] INFO datanode.DataNode
> (DataNode.java:initIpcServer(1029)) - Opened IPC server at /127.0.0.1:50140
> 2017-08-30 18:02:37,979 [Thread-1025] INFO impl.FsDatasetImpl
> (FsVolumeList.java:run(414)) - Time taken to scan block pool
> BP-1775344991-172.17.0.2-1504116157738 on
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1:
> 10ms
> 2017-08-30 18:02:37,979 [Thread-997] INFO impl.FsDatasetImpl
> (FsVolumeList.java:addBlockPool(440)) - Total time to scan all replicas for
> block pool BP-1775344991-172.17.0.2-1504116157738: 10ms
> 2017-08-30 18:02:37,979 [Thread-1032] INFO impl.FsDatasetImpl
> (FsVolumeList.java:run(198)) - Adding replicas to map for block pool
> BP-1775344991-172.17.0.2-1504116157738 on volume
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1...
> 2017-08-30 18:02:37,979 [Thread-1033] INFO impl.FsDatasetImpl
> (FsVolumeList.java:run(198)) - Adding replicas to map for block pool
> BP-1775344991-172.17.0.2-1504116157738 on volume
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2...
> 2017-08-30 18:02:37,980 [Thread-1032] INFO impl.BlockPoolSlice
> (BlockPoolSlice.java:readReplicasFromCache(770)) - Replica Cache file:
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1/current/BP-1775344991-172.17.0.2-1504116157738/current/replicas
> doesn't exist
> 2017-08-30 18:02:37,980 [Thread-1033] INFO impl.BlockPoolSlice
> (BlockPoolSlice.java:readReplicasFromCache(770)) - Replica Cache file:
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2/current/BP-1775344991-172.17.0.2-1504116157738/current/replicas
> doesn't exist
> 2017-08-30 18:02:37,980 [Thread-1032] INFO impl.FsDatasetImpl
> (FsVolumeList.java:run(203)) - Time to add replicas to map for block pool
> BP-1775344991-172.17.0.2-1504116157738 on volume
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1:
> 0ms
> 2017-08-30 18:02:37,980 [Thread-1033] INFO impl.FsDatasetImpl
> (FsVolumeList.java:run(203)) - Time to add replicas to map for block pool
> BP-1775344991-172.17.0.2-1504116157738 on volume
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2:
> 0ms
> 2017-08-30 18:02:37,980 [Thread-997] INFO impl.FsDatasetImpl
> (FsVolumeList.java:getAllVolumesMap(229)) - Total time to add all replicas to
> map: 1ms
> 2017-08-30 18:02:37,980 [main] INFO datanode.DataNode
> (BlockPoolManager.java:refreshNamenodes(149)) - Refresh request received for
> nameservices: null
> 2017-08-30 18:02:37,980 [main] INFO datanode.DataNode
> (BlockPoolManager.java:doRefreshNamenodes(198)) - Starting BPOfferServices
> for nameservices: <default>
> 2017-08-30 18:02:37,980
> [VolumeScannerThread(/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1)]
> INFO datanode.VolumeScanner
> (VolumeScanner.java:findNextUsableBlockIter(382)) - Now scanning bpid
> BP-1775344991-172.17.0.2-1504116157738 on volume
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1
> 2017-08-30 18:02:37,981 [Thread-997] INFO datanode.DirectoryScanner
> (DirectoryScanner.java:start(281)) - Periodic Directory Tree Verification
> scan starting at 8/30/17 8:12 PM with interval of 21600000ms
> 2017-08-30 18:02:37,980
> [VolumeScannerThread(/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2)]
> INFO datanode.VolumeScanner
> (VolumeScanner.java:findNextUsableBlockIter(382)) - Now scanning bpid
> BP-1775344991-172.17.0.2-1504116157738 on volume
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2
> 2017-08-30 18:02:37,981
> [VolumeScannerThread(/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1)]
> INFO datanode.VolumeScanner (VolumeScanner.java:runLoop(538)) -
> VolumeScanner(/testptch/hadoop/h
> ...[truncated 43082 chars]...
> :02:38,122 [IPC Server handler 0 on 47551] INFO net.NetworkTopology
> (NetworkTopology.java:add(145)) - Adding a new node:
> /default-rack/127.0.0.1:46540
> 2017-08-30 18:02:38,122 [IPC Server handler 0 on 47551] INFO
> blockmanagement.BlockReportLeaseManager
> (BlockReportLeaseManager.java:registerNode(204)) - Registered DN
> 303e97cb-9549-4084-8530-e6f511ebcbe1 (127.0.0.1:46540).
> 2017-08-30 18:02:38,123 [BP-1775344991-172.17.0.2-1504116157738 heartbeating
> to localhost/127.0.0.1:47551] INFO datanode.DataNode
> (BPServiceActor.java:register(782)) - Block pool Block pool
> BP-1775344991-172.17.0.2-1504116157738 (Datanode Uuid
> 303e97cb-9549-4084-8530-e6f511ebcbe1) service to localhost/127.0.0.1:47551
> successfully registered with NN
> 2017-08-30 18:02:38,123 [BP-1775344991-172.17.0.2-1504116157738 heartbeating
> to localhost/127.0.0.1:47551] INFO datanode.DataNode
> (BPServiceActor.java:offerService(612)) - For namenode
> localhost/127.0.0.1:47551 using BLOCKREPORT_INTERVAL of 21600000msec
> CACHEREPORT_INTERVAL of 10000msec Initial delay: 0msec; heartBeatInterval=3000
> 2017-08-30 18:02:38,126 [IPC Server handler 1 on 47551] INFO
> blockmanagement.DatanodeDescriptor
> (DatanodeDescriptor.java:updateStorage(937)) - Adding new storage ID
> DS-3f87b7ae-9ac7-4485-885e-fc9d2475df21 for DN 127.0.0.1:46540
> 2017-08-30 18:02:38,126 [IPC Server handler 1 on 47551] INFO
> blockmanagement.DatanodeDescriptor
> (DatanodeDescriptor.java:updateStorage(937)) - Adding new storage ID
> DS-a58905ea-f4b4-4b7f-8c16-587ae6b9033b for DN 127.0.0.1:46540
> 2017-08-30 18:02:38,127 [Block report processor] INFO BlockStateChange
> (BlockManager.java:processReport(2437)) - BLOCK* processReport
> 0x703473b98bf5005f: Processing first storage report for
> DS-a58905ea-f4b4-4b7f-8c16-587ae6b9033b from datanode
> 303e97cb-9549-4084-8530-e6f511ebcbe1
> 2017-08-30 18:02:38,128 [Block report processor] INFO BlockStateChange
> (BlockManager.java:processReport(2463)) - BLOCK* processReport
> 0x703473b98bf5005f: from storage DS-a58905ea-f4b4-4b7f-8c16-587ae6b9033b node
> DatanodeRegistration(127.0.0.1:46540,
> datanodeUuid=303e97cb-9549-4084-8530-e6f511ebcbe1, infoPort=41583,
> infoSecurePort=0, ipcPort=56578,
> storageInfo=lv=-57;cid=testClusterID;nsid=785578744;c=1504116157738), blocks:
> 0, hasStaleStorage: true, processing time: 0 msecs, invalidatedBlocks: 0
> 2017-08-30 18:02:38,128 [Block report processor] INFO BlockStateChange
> (BlockManager.java:processReport(2437)) - BLOCK* processReport
> 0x703473b98bf5005f: Processing first storage report for
> DS-3f87b7ae-9ac7-4485-885e-fc9d2475df21 from datanode
> 303e97cb-9549-4084-8530-e6f511ebcbe1
> 2017-08-30 18:02:38,128 [Block report processor] INFO BlockStateChange
> (BlockManager.java:processReport(2463)) - BLOCK* processReport
> 0x703473b98bf5005f: from storage DS-3f87b7ae-9ac7-4485-885e-fc9d2475df21 node
> DatanodeRegistration(127.0.0.1:46540,
> datanodeUuid=303e97cb-9549-4084-8530-e6f511ebcbe1, infoPort=41583,
> infoSecurePort=0, ipcPort=56578,
> storageInfo=lv=-57;cid=testClusterID;nsid=785578744;c=1504116157738), blocks:
> 0, hasStaleStorage: false, processing time: 0 msecs, invalidatedBlocks: 0
> 2017-08-30 18:02:38,129 [BP-1775344991-172.17.0.2-1504116157738 heartbeating
> to localhost/127.0.0.1:47551] INFO datanode.DataNode
> (BPServiceActor.java:blockReport(422)) - Successfully sent block report
> 0x703473b98bf5005f, containing 2 storage report(s), of which we sent 2. The
> reports had 0 total blocks and used 1 RPC(s). This took 0 msec to generate
> and 2 msecs for RPC and NN processing. Got back one command:
> FinalizeCommand/5.
> 2017-08-30 18:02:38,129 [BP-1775344991-172.17.0.2-1504116157738 heartbeating
> to localhost/127.0.0.1:47551] INFO datanode.DataNode
> (BPOfferService.java:processCommandFromActive(745)) - Got finalize command
> for block pool BP-1775344991-172.17.0.2-1504116157738
> 2017-08-30 18:02:38,160 [main] INFO hdfs.MiniDFSCluster
> (MiniDFSCluster.java:waitActive(2621)) - Cluster is active
> 2017-08-30 18:02:38,163 [main] INFO hdfs.MiniDFSCluster
> (MiniDFSCluster.java:waitActive(2621)) - Cluster is active
> 2017-08-30 18:02:38,168 [IPC Server handler 5 on 47551] INFO
> FSNamesystem.audit (FSNamesystem.java:logAuditMessage(7598)) - allowed=true
> ugi=jenkins (auth:SIMPLE) ip=/127.0.0.1 cmd=create
> src=/user/jenkins/noheartbeat.dat dst=null
> perm=jenkins:supergroup:rw-r--r-- proto=rpc
> 2017-08-30 18:02:38,174 [IPC Server handler 6 on 47551] INFO
> hdfs.StateChange (FSDirWriteFileOp.java:logAllocatedBlock(789)) - BLOCK*
> allocate blk_1073741825_1001, replicas=127.0.0.1:46794, 127.0.0.1:51925 for
> /user/jenkins/noheartbeat.dat
> 2017-08-30 18:02:38,177 [DataXceiver for client
> DFSClient_NONMAPREDUCE_-172490240_1 at /127.0.0.1:54220 [Receiving block
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001]] INFO
> datanode.DataNode (DataXceiver.java:writeBlock(742)) - Receiving
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001 src:
> /127.0.0.1:54220 dest: /127.0.0.1:46794
> 2017-08-30 18:02:38,178 [DataXceiver for client
> DFSClient_NONMAPREDUCE_-172490240_1 at /127.0.0.1:56224 [Receiving block
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001]] INFO
> datanode.DataNode (DataXceiver.java:writeBlock(742)) - Receiving
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001 src:
> /127.0.0.1:56224 dest: /127.0.0.1:51925
> 2017-08-30 18:02:39,181 [DataXceiver for client
> DFSClient_NONMAPREDUCE_-172490240_1 at /127.0.0.1:56224 [Receiving block
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001]] INFO
> datanode.DataNode (BlockReceiver.java:receiveBlock(1001)) - Exception for
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001
> java.net.SocketTimeoutException: 1000 millis timeout while waiting for
> channel to be ready for read. ch : java.nio.channels.SocketChannel[connected
> local=/127.0.0.1:51925 remote=/127.0.0.1:56224]
> at
> org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:164)
> at
> org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:161)
> at
> org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:131)
> at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
> at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
> at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
> at java.io.DataInputStream.read(DataInputStream.java:149)
> at org.apache.hadoop.io.IOUtils.readFully(IOUtils.java:208)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.PacketReceiver.doReadFully(PacketReceiver.java:211)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.PacketReceiver.doRead(PacketReceiver.java:134)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.PacketReceiver.receiveNextPacket(PacketReceiver.java:109)
> at
> org.apache.hadoop.hdfs.server.datanode.BlockReceiver.receivePacket(BlockReceiver.java:522)
> at
> org.apache.hadoop.hdfs.server.datanode.BlockReceiver.receiveBlock(BlockReceiver.java:962)
> at
> org.apache.hadoop.hdfs.server.datanode.DataXceiver.writeBlock(DataXceiver.java:900)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opWriteBlock(Receiver.java:173)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:107)
> at
> org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:290)
> at java.lang.Thread.run(Thread.java:748)
> 2017-08-30 18:02:39,182 [PacketResponder:
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001,
> type=LAST_IN_PIPELINE] INFO datanode.DataNode (BlockReceiver.java:run(1461))
> - PacketResponder:
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001,
> type=LAST_IN_PIPELINE: Thread is interrupted.
> 2017-08-30 18:02:39,182 [PacketResponder:
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001,
> type=LAST_IN_PIPELINE] INFO datanode.DataNode (BlockReceiver.java:run(1497))
> - PacketResponder:
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001,
> type=LAST_IN_PIPELINE terminating
> 2017-08-30 18:02:39,182 [DataXceiver for client
> DFSClient_NONMAPREDUCE_-172490240_1 at /127.0.0.1:56224 [Receiving block
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001]] INFO
> datanode.DataNode (DataXceiver.java:writeBlock(933)) - opWriteBlock
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001 received exception
> java.net.SocketTimeoutException: 1000 millis timeout while waiting for
> channel to be ready for read. ch : java.nio.channels.SocketChannel[connected
> local=/127.0.0.1:51925 remote=/127.0.0.1:56224]
> 2017-08-30 18:02:39,183 [DataXceiver for client
> DFSClient_NONMAPREDUCE_-172490240_1 at /127.0.0.1:56224 [Receiving block
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001]] ERROR
> datanode.DataNode (DataXceiver.java:run(323)) - 127.0.0.1:51925:DataXceiver
> error processing WRITE_BLOCK operation src: /127.0.0.1:56224 dst:
> /127.0.0.1:51925
> java.net.SocketTimeoutException: 1000 millis timeout while waiting for
> channel to be ready for read. ch : java.nio.channels.SocketChannel[connected
> local=/127.0.0.1:51925 remote=/127.0.0.1:56224]
> at
> org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:164)
> at
> org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:161)
> at
> org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:131)
> at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
> at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
> at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
> at java.io.DataInputStream.read(DataInputStream.java:149)
> at org.apache.hadoop.io.IOUtils.readFully(IOUtils.java:208)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.PacketReceiver.doReadFully(PacketReceiver.java:211)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.PacketReceiver.doRead(PacketReceiver.java:134)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.PacketReceiver.receiveNextPacket(PacketReceiver.java:109)
> at
> org.apache.hadoop.hdfs.server.datanode.BlockReceiver.receivePacket(BlockReceiver.java:522)
> at
> org.apache.hadoop.hdfs.server.datanode.BlockReceiver.receiveBlock(BlockReceiver.java:962)
> at
> org.apache.hadoop.hdfs.server.datanode.DataXceiver.writeBlock(DataXceiver.java:900)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opWriteBlock(Receiver.java:173)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:107)
> at
> org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:290)
> at java.lang.Thread.run(Thread.java:748)
> 2017-08-30 18:02:39,183 [PacketResponder:
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001,
> type=HAS_DOWNSTREAM_IN_PIPELINE, downstreams=1:[127.0.0.1:51925]] INFO
> datanode.DataNode (BlockReceiver.java:packetSentInTime(393)) - A packet was
> last sent 1006 milliseconds ago.
> 2017-08-30 18:02:39,186 [PacketResponder:
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001,
> type=HAS_DOWNSTREAM_IN_PIPELINE, downstreams=1:[127.0.0.1:51925]] WARN
> datanode.DataNode (BlockReceiver.java:run(1436)) - The downstream error might
> be due to congestion in upstream including this node. Propagating the error:
> java.io.EOFException: Unexpected EOF while trying to read response from server
> at
> org.apache.hadoop.hdfs.protocolPB.PBHelperClient.vintPrefixed(PBHelperClient.java:444)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.PipelineAck.readFields(PipelineAck.java:213)
> at
> org.apache.hadoop.hdfs.server.datanode.BlockReceiver$PacketResponder.run(BlockReceiver.java:1375)
> at java.lang.Thread.run(Thread.java:748)
> 2017-08-30 18:02:39,186 [PacketResponder:
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001,
> type=HAS_DOWNSTREAM_IN_PIPELINE, downstreams=1:[127.0.0.1:51925]] WARN
> datanode.DataNode (BlockReceiver.java:run(1480)) - IOException in
> BlockReceiver.run():
> java.io.EOFException: Unexpected EOF while trying to read response from server
> at
> org.apache.hadoop.hdfs.protocolPB.PBHelperClient.vintPrefixed(PBHelperClient.java:444)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.PipelineAck.readFields(PipelineAck.java:213)
> at
> org.apache.hadoop.hdfs.server.datanode.BlockReceiver$PacketResponder.run(BlockReceiver.java:1375)
> at java.lang.Thread.run(Thread.java:748)
> 2017-08-30 18:02:39,186 [PacketResponder:
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001,
> type=HAS_DOWNSTREAM_IN_PIPELINE, downstreams=1:[127.0.0.1:51925]] INFO
> datanode.DataNode (BlockReceiver.java:run(1483)) - PacketResponder:
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001,
> type=HAS_DOWNSTREAM_IN_PIPELINE, downstreams=1:[127.0.0.1:51925]
> java.io.EOFException: Unexpected EOF while trying to read response from server
> at
> org.apache.hadoop.hdfs.protocolPB.PBHelperClient.vintPrefixed(PBHelperClient.java:444)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.PipelineAck.readFields(PipelineAck.java:213)
> at
> org.apache.hadoop.hdfs.server.datanode.BlockReceiver$PacketResponder.run(BlockReceiver.java:1375)
> at java.lang.Thread.run(Thread.java:748)
> 2017-08-30 18:02:39,186 [PacketResponder:
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001,
> type=HAS_DOWNSTREAM_IN_PIPELINE, downstreams=1:[127.0.0.1:51925]] INFO
> datanode.DataNode (BlockReceiver.java:run(1497)) - PacketResponder:
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001,
> type=HAS_DOWNSTREAM_IN_PIPELINE, downstreams=1:[127.0.0.1:51925] terminating
> 2017-08-30 18:02:39,186 [DataXceiver for client
> DFSClient_NONMAPREDUCE_-172490240_1 at /127.0.0.1:54220 [Receiving block
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001]] INFO
> datanode.DataNode (BlockReceiver.java:handleMirrorOutError(447)) -
> DatanodeRegistration(127.0.0.1:46794,
> datanodeUuid=d7ee1847-d046-47ea-9a05-7fd25bcb1e86, infoPort=52625,
> infoSecurePort=0, ipcPort=58248,
> storageInfo=lv=-57;cid=testClusterID;nsid=785578744;c=1504116157738):Exception
> writing BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001 to mirror
> 127.0.0.1:51925
> java.io.IOException: Interrupted while sleeping. Bailing out.
> at
> org.apache.hadoop.hdfs.TestClientProtocolForPipelineRecovery$6.stopSendingPacketDownstream(TestClientProtocolForPipelineRecovery.java:558)
> at
> org.apache.hadoop.hdfs.server.datanode.BlockReceiver.receivePacket(BlockReceiver.java:581)
> at
> org.apache.hadoop.hdfs.server.datanode.BlockReceiver.receiveBlock(BlockReceiver.java:962)
> at
> org.apache.hadoop.hdfs.server.datanode.DataXceiver.writeBlock(DataXceiver.java:900)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opWriteBlock(Receiver.java:173)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:107)
> at
> org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:290)
> at java.lang.Thread.run(Thread.java:748)
> 2017-08-30 18:02:49,187 [ResponseProcessor for block
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001] WARN
> hdfs.DataStreamer (DataStreamer.java:run(1214)) - Exception for
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001
> java.net.SocketTimeoutException: 11000 millis timeout while waiting for
> channel to be ready for read. ch : java.nio.channels.SocketChannel[connected
> local=/127.0.0.1:54220 remote=/127.0.0.1:46794]
> at
> org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:164)
> at
> org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:161)
> at
> org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:131)
> at
> org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:118)
> at java.io.FilterInputStream.read(FilterInputStream.java:83)
> at java.io.FilterInputStream.read(FilterInputStream.java:83)
> at
> org.apache.hadoop.hdfs.protocolPB.PBHelperClient.vintPrefixed(PBHelperClient.java:442)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.PipelineAck.readFields(PipelineAck.java:213)
> at
> org.apache.hadoop.hdfs.DataStreamer$ResponseProcessor.run(DataStreamer.java:1104)
> 2017-08-30 18:02:49,188 [DataStreamer for file /user/jenkins/noheartbeat.dat
> block BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001] WARN
> hdfs.DataStreamer (DataStreamer.java:handleBadDatanode(1560)) - Error
> Recovery for BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001 in
> pipeline
> [DatanodeInfoWithStorage[127.0.0.1:46794,DS-230ffa8a-d07d-4ac0-86e2-9acc7403dc9d,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:51925,DS-274e8cc9-280b-4370-b494-6a4f0d67ccf4,DISK]]:
> datanode
> 0(DatanodeInfoWithStorage[127.0.0.1:46794,DS-230ffa8a-d07d-4ac0-86e2-9acc7403dc9d,DISK])
> is bad.
> 2017-08-30 18:02:49,188 [DataXceiver for client
> DFSClient_NONMAPREDUCE_-172490240_1 at /127.0.0.1:54220 [Receiving block
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001]] INFO
> datanode.DataNode (BlockReceiver.java:receiveBlock(1001)) - Exception for
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001
> java.io.IOException: Premature EOF from inputStream
> at org.apache.hadoop.io.IOUtils.readFully(IOUtils.java:210)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.PacketReceiver.doReadFully(PacketReceiver.java:211)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.PacketReceiver.doRead(PacketReceiver.java:134)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.PacketReceiver.receiveNextPacket(PacketReceiver.java:109)
> at
> org.apache.hadoop.hdfs.server.datanode.BlockReceiver.receivePacket(BlockReceiver.java:522)
> at
> org.apache.hadoop.hdfs.server.datanode.BlockReceiver.receiveBlock(BlockReceiver.java:962)
> at
> org.apache.hadoop.hdfs.server.datanode.DataXceiver.writeBlock(DataXceiver.java:900)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opWriteBlock(Receiver.java:173)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:107)
> at
> org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:290)
> at java.lang.Thread.run(Thread.java:748)
> 2017-08-30 18:02:49,188 [DataXceiver for client
> DFSClient_NONMAPREDUCE_-172490240_1 at /127.0.0.1:54220 [Receiving block
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001]] INFO
> datanode.DataNode (DataXceiver.java:writeBlock(933)) - opWriteBlock
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001 received exception
> java.io.IOException: Premature EOF from inputStream
> 2017-08-30 18:02:49,189 [DataXceiver for client
> DFSClient_NONMAPREDUCE_-172490240_1 at /127.0.0.1:54220 [Receiving block
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001]] ERROR
> datanode.DataNode (DataXceiver.java:run(323)) - 127.0.0.1:46794:DataXceiver
> error processing WRITE_BLOCK operation src: /127.0.0.1:54220 dst:
> /127.0.0.1:46794
> java.io.IOException: Premature EOF from inputStream
> at org.apache.hadoop.io.IOUtils.readFully(IOUtils.java:210)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.PacketReceiver.doReadFully(PacketReceiver.java:211)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.PacketReceiver.doRead(PacketReceiver.java:134)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.PacketReceiver.receiveNextPacket(PacketReceiver.java:109)
> at
> org.apache.hadoop.hdfs.server.datanode.BlockReceiver.receivePacket(BlockReceiver.java:522)
> at
> org.apache.hadoop.hdfs.server.datanode.BlockReceiver.receiveBlock(BlockReceiver.java:962)
> at
> org.apache.hadoop.hdfs.server.datanode.DataXceiver.writeBlock(DataXceiver.java:900)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opWriteBlock(Receiver.java:173)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:107)
> at
> org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:290)
> at java.lang.Thread.run(Thread.java:748)
> 2017-08-30 18:02:49,214 [DataXceiver for client
> DFSClient_NONMAPREDUCE_-172490240_1 at /127.0.0.1:55316 [Receiving block
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001]] INFO
> datanode.DataNode (DataXceiver.java:writeBlock(742)) - Receiving
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001 src:
> /127.0.0.1:55316 dest: /127.0.0.1:46540
> 2017-08-30 18:02:49,214 [DataXceiver for client
> DFSClient_NONMAPREDUCE_-172490240_1 at /127.0.0.1:55315 [Receiving block
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001]] INFO
> datanode.DataNode (DataXceiver.java:writeBlock(742)) - Receiving
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001 src:
> /127.0.0.1:55315 dest: /127.0.0.1:46540
> 2017-08-30 18:02:49,215 [DataXceiver for client
> DFSClient_NONMAPREDUCE_-172490240_1 at /127.0.0.1:55316 [Receiving block
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001]] INFO
> impl.FsDatasetImpl (FsDatasetImpl.java:recoverRbw(1376)) - Recover RBW
> replica BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001
> 2017-08-30 18:02:49,215
> [org.apache.hadoop.hdfs.server.datanode.DataNode$DataTransfer@47d9e1e8] INFO
> datanode.DataNode (DataNode.java:run(2520)) - DataTransfer, at
> 127.0.0.1:51925: Transmitted
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001 (numBytes=0) to
> /127.0.0.1:46540
> 2017-08-30 18:02:49,215 [DataXceiver for client
> DFSClient_NONMAPREDUCE_-172490240_1 at /127.0.0.1:55316 [Receiving block
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001]] INFO
> datanode.DataNode (DataXceiver.java:writeBlock(933)) - opWriteBlock
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001 received exception
> org.apache.hadoop.hdfs.server.datanode.ReplicaNotFoundException: Cannot
> recover a non-RBW replica LocalReplicaInPipeline, blk_1073741825_1001,
> TEMPORARY
> getNumBytes() = 0
> getBytesOnDisk() = 0
> getVisibleLength()= -1
> getVolume() =
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data5
> getBlockURI() =
> file:/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data5/current/BP-1775344991-172.17.0.2-1504116157738/tmp/blk_1073741825
> bytesAcked=0
> bytesOnDisk=0
> 2017-08-30 18:02:49,215 [DataXceiver for client
> DFSClient_NONMAPREDUCE_-172490240_1 at /127.0.0.1:55315 [Receiving block
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001]] INFO
> impl.FsDatasetImpl (FsDatasetImpl.java:convertTemporaryToRbw(1470)) - Convert
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001 from Temporary to
> RBW, visible length=0
> 2017-08-30 18:02:49,215 [DataXceiver for client
> DFSClient_NONMAPREDUCE_-172490240_1 at /127.0.0.1:55316 [Receiving block
> BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001]] ERROR
> datanode.DataNode (DataXceiver.java:run(323)) - 127.0.0.1:46540:DataXceiver
> error processing WRITE_BLOCK operation src: /127.0.0.1:55316 dst:
> /127.0.0.1:46540
> org.apache.hadoop.hdfs.server.datanode.ReplicaNotFoundException: Cannot
> recover a non-RBW replica LocalReplicaInPipeline, blk_1073741825_1001,
> TEMPORARY
> getNumBytes() = 0
> getBytesOnDisk() = 0
> getVisibleLength()= -1
> getVolume() =
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data5
> getBlockURI() =
> file:/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data5/current/BP-1775344991-172.17.0.2-1504116157738/tmp/blk_1073741825
> bytesAcked=0
> bytesOnDisk=0
> at
> org.apache.hadoop.hdfs.server.datanode.fsdataset.impl.FsDatasetImpl.recoverRbw(FsDatasetImpl.java:1385)
> at
> org.apache.hadoop.hdfs.server.datanode.BlockReceiver.<init>(BlockReceiver.java:221)
> at
> org.apache.hadoop.hdfs.server.datanode.DataXceiver.getBlockReceiver(DataXceiver.java:1291)
> at
> org.apache.hadoop.hdfs.server.datanode.DataXceiver.writeBlock(DataXceiver.java:758)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opWriteBlock(Receiver.java:173)
> at
> org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:107)
> at
> org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:290)
> at java.lang.Thread.run(Thread.java:748)
> 2017-08-30 18:02:49,216 [DataStreamer for file /user/jenkins/noheartbeat.dat
> block BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001] INFO
> hdfs.DataStreamer (DataStreamer.java:createBlockOutputStream(1778)) -
> Exception in createBlockOutputStream blk_1073741825_1001
> java.io.EOFException: Unexpected EOF while trying to read response from server
> at
> org.apache.hadoop.hdfs.protocolPB.PBHelperClient.vintPrefixed(PBHelperClient.java:444)
> at
> org.apache.hadoop.hdfs.DataStreamer.createBlockOutputStream(DataStreamer.java:1751)
> at
> org.apache.hadoop.hdfs.DataStreamer.setupPipelineInternal(DataStreamer.java:1496)
> at
> org.apache.hadoop.hdfs.DataStreamer.setupPipelineForAppendOrRecovery(DataStreamer.java:1470)
> at
> org.apache.hadoop.hdfs.DataStreamer.processDatanodeOrExternalError(DataStreamer.java:1274)
> at org.apache.hadoop.hdfs.DataStreamer.run(DataStreamer.java:684)
> 2017-08-30 18:02:49,217 [DataStreamer for file /user/jenkins/noheartbeat.dat
> block BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001] WARN
> hdfs.DataStreamer (DataStreamer.java:handleBadDatanode(1560)) - Error
> Recovery for BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001 in
> pipeline
> [DatanodeInfoWithStorage[127.0.0.1:46540,DS-a58905ea-f4b4-4b7f-8c16-587ae6b9033b,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:51925,DS-274e8cc9-280b-4370-b494-6a4f0d67ccf4,DISK]]:
> datanode
> 0(DatanodeInfoWithStorage[127.0.0.1:46540,DS-a58905ea-f4b4-4b7f-8c16-587ae6b9033b,DISK])
> is bad.
> 2017-08-30 18:02:49,218 [IPC Server handler 0 on 47551] WARN
> blockmanagement.BlockPlacementPolicy
> (BlockPlacementPolicyDefault.java:chooseTarget(405)) - Failed to place enough
> replicas, still in need of 1 to reach 2 (unavailableStorages=[],
> storagePolicy=BlockStoragePolicy{HOT:7, storageTypes=[DISK],
> creationFallbacks=[], replicationFallbacks=[ARCHIVE]}, newBlock=false) For
> more information, please enable DEBUG log level on
> org.apache.hadoop.hdfs.server.blockmanagement.BlockPlacementPolicy and
> org.apache.hadoop.net.NetworkTopology
> 2017-08-30 18:02:49,219 [IPC Server handler 0 on 47551] WARN
> blockmanagement.BlockPlacementPolicy
> (BlockPlacementPolicyDefault.java:chooseTarget(405)) - Failed to place enough
> replicas, still in need of 1 to reach 2 (unavailableStorages=[DISK],
> storagePolicy=BlockStoragePolicy{HOT:7, storageTypes=[DISK],
> creationFallbacks=[], replicationFallbacks=[ARCHIVE]}, newBlock=false) For
> more information, please enable DEBUG log level on
> org.apache.hadoop.hdfs.server.blockmanagement.BlockPlacementPolicy and
> org.apache.hadoop.net.NetworkTopology
> 2017-08-30 18:02:49,348 [IPC Server handler 0 on 47551] WARN
> protocol.BlockStoragePolicy (BlockStoragePolicy.java:chooseStorageTypes(161))
> - Failed to place enough replicas: expected size is 1 but only 0 storage
> types can be selected (replication=2, selected=[], unavailable=[DISK,
> ARCHIVE], removed=[DISK], policy=BlockStoragePolicy{HOT:7,
> storageTypes=[DISK], creationFallbacks=[], replicationFallbacks=[ARCHIVE]})
> 2017-08-30 18:02:49,348 [IPC Server handler 0 on 47551] WARN
> blockmanagement.BlockPlacementPolicy
> (BlockPlacementPolicyDefault.java:chooseTarget(405)) - Failed to place enough
> replicas, still in need of 1 to reach 2 (unavailableStorages=[DISK, ARCHIVE],
> storagePolicy=BlockStoragePolicy{HOT:7, storageTypes=[DISK],
> creationFallbacks=[], replicationFallbacks=[ARCHIVE]}, newBlock=false) All
> required storage types are unavailable: unavailableStorages=[DISK, ARCHIVE],
> storagePolicy=BlockStoragePolicy{HOT:7, storageTypes=[DISK],
> creationFallbacks=[], replicationFallbacks=[ARCHIVE]}
> 2017-08-30 18:02:49,354 [DataStreamer for file /user/jenkins/noheartbeat.dat
> block BP-1775344991-172.17.0.2-1504116157738:blk_1073741825_1001] WARN
> hdfs.DataStreamer (DataStreamer.java:run(844)) - DataStreamer Exception
> java.io.IOException: Failed to replace a bad datanode on the existing
> pipeline due to no more good datanodes being available to try. (Nodes:
> current=[DatanodeInfoWithStorage[127.0.0.1:51925,DS-274e8cc9-280b-4370-b494-6a4f0d67ccf4,DISK]],
>
> original=[DatanodeInfoWithStorage[127.0.0.1:51925,DS-274e8cc9-280b-4370-b494-6a4f0d67ccf4,DISK]]).
> The current failed datanode replacement policy is ALWAYS, and a client may
> configure this via
> 'dfs.client.block.write.replace-datanode-on-failure.policy' in its
> configuration.
> at
> org.apache.hadoop.hdfs.DataStreamer.findNewDatanode(DataStreamer.java:1322)
> at
> org.apache.hadoop.hdfs.DataStreamer.addDatanode2ExistingPipeline(DataStreamer.java:1388)
> at
> org.apache.hadoop.hdfs.DataStreamer.handleDatanodeReplacement(DataStreamer.java:1587)
> at
> org.apache.hadoop.hdfs.DataStreamer.setupPipelineInternal(DataStreamer.java:1488)
> at
> org.apache.hadoop.hdfs.DataStreamer.setupPipelineForAppendOrRecovery(DataStreamer.java:1470)
> at
> org.apache.hadoop.hdfs.DataStreamer.processDatanodeOrExternalError(DataStreamer.java:1274)
> at org.apache.hadoop.hdfs.DataStreamer.run(DataStreamer.java:684)
> 2017-08-30 18:02:49,355 [main] WARN hdfs.DFSClient
> (DFSOutputStream.java:flushOrSync(729)) - Error while syncing
> java.io.IOException: Failed to replace a bad datanode on the existing
> pipeline due to no more good datanodes being available to try. (Nodes:
> current=[DatanodeInfoWithStorage[127.0.0.1:51925,DS-274e8cc9-280b-4370-b494-6a4f0d67ccf4,DISK]],
>
> original=[DatanodeInfoWithStorage[127.0.0.1:51925,DS-274e8cc9-280b-4370-b494-6a4f0d67ccf4,DISK]]).
> The current failed datanode replacement policy is ALWAYS, and a client may
> configure this via
> 'dfs.client.block.write.replace-datanode-on-failure.policy' in its
> configuration.
> at
> org.apache.hadoop.hdfs.DataStreamer.findNewDatanode(DataStreamer.java:1322)
> at
> org.apache.hadoop.hdfs.DataStreamer.addDatanode2ExistingPipeline(DataStreamer.java:1388)
> at
> org.apache.hadoop.hdfs.DataStreamer.handleDatanodeReplacement(DataStreamer.java:1587)
> at
> org.apache.hadoop.hdfs.DataStreamer.setupPipelineInternal(DataStreamer.java:1488)
> at
> org.apache.hadoop.hdfs.DataStreamer.setupPipelineForAppendOrRecovery(DataStreamer.java:1470)
> at
> org.apache.hadoop.hdfs.DataStreamer.processDatanodeOrExternalError(DataStreamer.java:1274)
> at org.apache.hadoop.hdfs.DataStreamer.run(DataStreamer.java:684)
> 2017-08-30 18:02:49,357 [main] INFO hdfs.MiniDFSCluster
> (MiniDFSCluster.java:shutdown(1957)) - Shutting down the Mini HDFS Cluster
> 2017-08-30 18:02:49,357 [main] ERROR hdfs.DFSClient
> (DFSClient.java:closeAllFilesBeingWritten(590)) - Failed to close file:
> /user/jenkins/noheartbeat.dat with inode: 16388
> java.io.IOException: Failed to replace a bad datanode on the existing
> pipeline due to no more good datanodes being available to try. (Nodes:
> current=[DatanodeInfoWithStorage[127.0.0.1:51925,DS-274e8cc9-280b-4370-b494-6a4f0d67ccf4,DISK]],
>
> original=[DatanodeInfoWithStorage[127.0.0.1:51925,DS-274e8cc9-280b-4370-b494-6a4f0d67ccf4,DISK]]).
> The current failed datanode replacement policy is ALWAYS, and a client may
> configure this via
> 'dfs.client.block.write.replace-datanode-on-failure.policy' in its
> configuration.
> at
> org.apache.hadoop.hdfs.DataStreamer.findNewDatanode(DataStreamer.java:1322)
> at
> org.apache.hadoop.hdfs.DataStreamer.addDatanode2ExistingPipeline(DataStreamer.java:1388)
> at
> org.apache.hadoop.hdfs.DataStreamer.handleDatanodeReplacement(DataStreamer.java:1587)
> at
> org.apache.hadoop.hdfs.DataStreamer.setupPipelineInternal(DataStreamer.java:1488)
> at
> org.apache.hadoop.hdfs.DataStreamer.setupPipelineForAppendOrRecovery(DataStreamer.java:1470)
> at
> org.apache.hadoop.hdfs.DataStreamer.processDatanodeOrExternalError(DataStreamer.java:1274)
> at org.apache.hadoop.hdfs.DataStreamer.run(DataStreamer.java:684)
> 2017-08-30 18:02:49,357 [main] INFO hdfs.MiniDFSCluster
> (MiniDFSCluster.java:shutdownDataNode(2005)) - Shutting down DataNode 2
> 2017-08-30 18:02:49,358 [main] WARN datanode.DirectoryScanner
> (DirectoryScanner.java:shutdown(340)) - DirectoryScanner: shutdown has been
> called
> 2017-08-30 18:02:49,358
> [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@70c0a3d5] INFO
> datanode.DataNode (DataXceiverServer.java:closeAllPeers(281)) - Closing all
> peers.
> 2017-08-30 18:02:49,359
> [VolumeScannerThread(/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data6)]
> INFO datanode.VolumeScanner (VolumeScanner.java:run(636)) -
> VolumeScanner(/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data6,
> DS-a58905ea-f4b4-4b7f-8c16-587ae6b9033b) exiting.
> 2017-08-30 18:02:49,359
> [VolumeScannerThread(/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data5)]
> INFO datanode.VolumeScanner (VolumeScanner.java:run(636)) -
> VolumeScanner(/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data5,
> DS-3f87b7ae-9ac7-4485-885e-fc9d2475df21) exiting.
> 2017-08-30 18:02:49,366 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStop(910)) - Stopped
> o.e.j.w.WebAppContext@36c0d0bd{/,null,UNAVAILABLE}{/datanode}
> 2017-08-30 18:02:49,368 [main] INFO server.AbstractConnector
> (AbstractConnector.java:doStop(318)) - Stopped
> ServerConnector@5e1fc2aa{HTTP/1.1,[http/1.1]}{localhost:0}
> 2017-08-30 18:02:49,368 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStop(910)) - Stopped
> o.e.j.s.ServletContextHandler@615e3f51{/static,file:///testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test-classes/webapps/static/,UNAVAILABLE}
> 2017-08-30 18:02:49,368 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStop(910)) - Stopped
> o.e.j.s.ServletContextHandler@2e51d054{/logs,file:///testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/log/,UNAVAILABLE}
> 2017-08-30 18:02:49,372 [main] INFO ipc.Server (Server.java:stop(3074)) -
> Stopping server on 56578
> 2017-08-30 18:02:49,372 [IPC Server listener on 56578] INFO ipc.Server
> (Server.java:run(1178)) - Stopping IPC Server listener on 56578
> 2017-08-30 18:02:49,373 [IPC Server Responder] INFO ipc.Server
> (Server.java:run(1312)) - Stopping IPC Server Responder
> 2017-08-30 18:02:49,373 [BP-1775344991-172.17.0.2-1504116157738 heartbeating
> to localhost/127.0.0.1:47551] WARN datanode.IncrementalBlockReportManager
> (IncrementalBlockReportManager.java:waitTillNextIBR(160)) -
> IncrementalBlockReportManager interrupted
> 2017-08-30 18:02:49,374 [BP-1775344991-172.17.0.2-1504116157738 heartbeating
> to localhost/127.0.0.1:47551] WARN datanode.DataNode
> (BPServiceActor.java:run(852)) - Ending block pool service for: Block pool
> BP-1775344991-172.17.0.2-1504116157738 (Datanode Uuid
> 303e97cb-9549-4084-8530-e6f511ebcbe1) service to localhost/127.0.0.1:47551
> 2017-08-30 18:02:49,374 [BP-1775344991-172.17.0.2-1504116157738 heartbeating
> to localhost/127.0.0.1:47551] INFO datanode.DataNode
> (BlockPoolManager.java:remove(102)) - Removed Block pool
> BP-1775344991-172.17.0.2-1504116157738 (Datanode Uuid
> 303e97cb-9549-4084-8530-e6f511ebcbe1)
> 2017-08-30 18:02:49,374 [BP-1775344991-172.17.0.2-1504116157738 heartbeating
> to localhost/127.0.0.1:47551] INFO impl.FsDatasetImpl
> (FsDatasetImpl.java:shutdownBlockPool(2675)) - Removing block pool
> BP-1775344991-172.17.0.2-1504116157738
> 2017-08-30 18:02:49,375
> [refreshUsed-/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data5/current/BP-1775344991-172.17.0.2-1504116157738]
> WARN fs.CachingGetSpaceUsed (CachingGetSpaceUsed.java:run(183)) - Thread
> Interrupted waiting to refresh disk information: sleep interrupted
> 2017-08-30 18:02:49,375
> [refreshUsed-/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data6/current/BP-1775344991-172.17.0.2-1504116157738]
> WARN fs.CachingGetSpaceUsed (CachingGetSpaceUsed.java:run(183)) - Thread
> Interrupted waiting to refresh disk information: sleep interrupted
> 2017-08-30 18:02:49,375 [main] INFO impl.FsDatasetAsyncDiskService
> (FsDatasetAsyncDiskService.java:shutdown(191)) - Shutting down all async disk
> service threads
> 2017-08-30 18:02:49,376 [main] INFO impl.FsDatasetAsyncDiskService
> (FsDatasetAsyncDiskService.java:shutdown(199)) - All async disk service
> threads have been shut down
> 2017-08-30 18:02:49,376 [main] INFO impl.RamDiskAsyncLazyPersistService
> (RamDiskAsyncLazyPersistService.java:shutdown(176)) - Shutting down all async
> lazy persist service threads
> 2017-08-30 18:02:49,376 [main] INFO impl.RamDiskAsyncLazyPersistService
> (RamDiskAsyncLazyPersistService.java:shutdown(183)) - All async lazy persist
> service threads have been shut down
> 2017-08-30 18:02:49,377 [main] INFO datanode.DataNode
> (DataNode.java:shutdown(2109)) - Shutdown complete.
> 2017-08-30 18:02:49,377 [main] INFO hdfs.MiniDFSCluster
> (MiniDFSCluster.java:shutdownDataNode(2005)) - Shutting down DataNode 1
> 2017-08-30 18:02:49,377 [main] WARN datanode.DirectoryScanner
> (DirectoryScanner.java:shutdown(340)) - DirectoryScanner: shutdown has been
> called
> 2017-08-30 18:02:49,377
> [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@44c13103] INFO
> datanode.DataNode (DataXceiverServer.java:closeAllPeers(281)) - Closing all
> peers.
> 2017-08-30 18:02:49,377
> [VolumeScannerThread(/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data3)]
> INFO datanode.VolumeScanner (VolumeScanner.java:run(636)) -
> VolumeScanner(/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data3,
> DS-274e8cc9-280b-4370-b494-6a4f0d67ccf4) exiting.
> 2017-08-30 18:02:49,378
> [VolumeScannerThread(/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data4)]
> INFO datanode.VolumeScanner (VolumeScanner.java:run(636)) -
> VolumeScanner(/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data4,
> DS-f402c2a1-2faf-489f-9a91-673666976433) exiting.
> 2017-08-30 18:02:49,382 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStop(910)) - Stopped
> o.e.j.w.WebAppContext@42b28ff1{/,null,UNAVAILABLE}{/datanode}
> 2017-08-30 18:02:49,383 [main] INFO server.AbstractConnector
> (AbstractConnector.java:doStop(318)) - Stopped
> ServerConnector@36061cf3{HTTP/1.1,[http/1.1]}{localhost:0}
> 2017-08-30 18:02:49,384 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStop(910)) - Stopped
> o.e.j.s.ServletContextHandler@481e91b6{/static,file:///testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test-classes/webapps/static/,UNAVAILABLE}
> 2017-08-30 18:02:49,384 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStop(910)) - Stopped
> o.e.j.s.ServletContextHandler@6631cb64{/logs,file:///testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/log/,UNAVAILABLE}
> 2017-08-30 18:02:49,385 [main] INFO ipc.Server (Server.java:stop(3074)) -
> Stopping server on 50140
> 2017-08-30 18:02:49,386 [IPC Server listener on 50140] INFO ipc.Server
> (Server.java:run(1178)) - Stopping IPC Server listener on 50140
> 2017-08-30 18:02:49,386 [IPC Server Responder] INFO ipc.Server
> (Server.java:run(1312)) - Stopping IPC Server Responder
> 2017-08-30 18:02:49,386 [BP-1775344991-172.17.0.2-1504116157738 heartbeating
> to localhost/127.0.0.1:47551] WARN datanode.IncrementalBlockReportManager
> (IncrementalBlockReportManager.java:waitTillNextIBR(160)) -
> IncrementalBlockReportManager interrupted
> 2017-08-30 18:02:49,387 [BP-1775344991-172.17.0.2-1504116157738 heartbeating
> to localhost/127.0.0.1:47551] WARN datanode.DataNode
> (BPServiceActor.java:run(852)) - Ending block pool service for: Block pool
> BP-1775344991-172.17.0.2-1504116157738 (Datanode Uuid
> 0bd5d006-5456-41c3-b8c3-c9c2a666a83a) service to localhost/127.0.0.1:47551
> 2017-08-30 18:02:49,387 [BP-1775344991-172.17.0.2-1504116157738 heartbeating
> to localhost/127.0.0.1:47551] INFO datanode.DataNode
> (BlockPoolManager.java:remove(102)) - Removed Block pool
> BP-1775344991-172.17.0.2-1504116157738 (Datanode Uuid
> 0bd5d006-5456-41c3-b8c3-c9c2a666a83a)
> 2017-08-30 18:02:49,387 [BP-1775344991-172.17.0.2-1504116157738 heartbeating
> to localhost/127.0.0.1:47551] INFO impl.FsDatasetImpl
> (FsDatasetImpl.java:shutdownBlockPool(2675)) - Removing block pool
> BP-1775344991-172.17.0.2-1504116157738
> 2017-08-30 18:02:49,388
> [refreshUsed-/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data3/current/BP-1775344991-172.17.0.2-1504116157738]
> WARN fs.CachingGetSpaceUsed (CachingGetSpaceUsed.java:run(183)) - Thread
> Interrupted waiting to refresh disk information: sleep interrupted
> 2017-08-30 18:02:49,388
> [refreshUsed-/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data4/current/BP-1775344991-172.17.0.2-1504116157738]
> WARN fs.CachingGetSpaceUsed (CachingGetSpaceUsed.java:run(183)) - Thread
> Interrupted waiting to refresh disk information: sleep interrupted
> 2017-08-30 18:02:49,389 [main] INFO impl.FsDatasetAsyncDiskService
> (FsDatasetAsyncDiskService.java:shutdown(191)) - Shutting down all async disk
> service threads
> 2017-08-30 18:02:49,389 [main] INFO impl.FsDatasetAsyncDiskService
> (FsDatasetAsyncDiskService.java:shutdown(199)) - All async disk service
> threads have been shut down
> 2017-08-30 18:02:49,389 [main] INFO impl.RamDiskAsyncLazyPersistService
> (RamDiskAsyncLazyPersistService.java:shutdown(176)) - Shutting down all async
> lazy persist service threads
> 2017-08-30 18:02:49,389 [main] INFO impl.RamDiskAsyncLazyPersistService
> (RamDiskAsyncLazyPersistService.java:shutdown(183)) - All async lazy persist
> service threads have been shut down
> 2017-08-30 18:02:49,390 [main] INFO datanode.DataNode
> (DataNode.java:shutdown(2109)) - Shutdown complete.
> 2017-08-30 18:02:49,390 [main] INFO hdfs.MiniDFSCluster
> (MiniDFSCluster.java:shutdownDataNode(2005)) - Shutting down DataNode 0
> 2017-08-30 18:02:49,390 [main] WARN datanode.DirectoryScanner
> (DirectoryScanner.java:shutdown(340)) - DirectoryScanner: shutdown has been
> called
> 2017-08-30 18:02:49,390
> [org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@3e17a0a1] INFO
> datanode.DataNode (DataXceiverServer.java:closeAllPeers(281)) - Closing all
> peers.
> 2017-08-30 18:02:49,391
> [VolumeScannerThread(/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2)]
> INFO datanode.VolumeScanner (VolumeScanner.java:run(636)) -
> VolumeScanner(/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2,
> DS-230ffa8a-d07d-4ac0-86e2-9acc7403dc9d) exiting.
> 2017-08-30 18:02:49,391
> [VolumeScannerThread(/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1)]
> INFO datanode.VolumeScanner (VolumeScanner.java:run(636)) -
> VolumeScanner(/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1,
> DS-c7f21b9d-2106-4d12-bb20-c414e1397d77) exiting.
> 2017-08-30 18:02:49,398 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStop(910)) - Stopped
> o.e.j.w.WebAppContext@29eda4f8{/,null,UNAVAILABLE}{/datanode}
> 2017-08-30 18:02:49,399 [main] INFO server.AbstractConnector
> (AbstractConnector.java:doStop(318)) - Stopped
> ServerConnector@1b9776f5{HTTP/1.1,[http/1.1]}{localhost:0}
> 2017-08-30 18:02:49,400 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStop(910)) - Stopped
> o.e.j.s.ServletContextHandler@7a7cc52c{/static,file:///testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test-classes/webapps/static/,UNAVAILABLE}
> 2017-08-30 18:02:49,400 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStop(910)) - Stopped
> o.e.j.s.ServletContextHandler@4e1ce44{/logs,file:///testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/log/,UNAVAILABLE}
> 2017-08-30 18:02:49,402 [main] INFO ipc.Server (Server.java:stop(3074)) -
> Stopping server on 58248
> 2017-08-30 18:02:49,403 [IPC Server listener on 58248] INFO ipc.Server
> (Server.java:run(1178)) - Stopping IPC Server listener on 58248
> 2017-08-30 18:02:49,403 [IPC Server Responder] INFO ipc.Server
> (Server.java:run(1312)) - Stopping IPC Server Responder
> 2017-08-30 18:02:49,403 [BP-1775344991-172.17.0.2-1504116157738 heartbeating
> to localhost/127.0.0.1:47551] WARN datanode.IncrementalBlockReportManager
> (IncrementalBlockReportManager.java:waitTillNextIBR(160)) -
> IncrementalBlockReportManager interrupted
> 2017-08-30 18:02:49,404 [BP-1775344991-172.17.0.2-1504116157738 heartbeating
> to localhost/127.0.0.1:47551] WARN datanode.DataNode
> (BPServiceActor.java:run(852)) - Ending block pool service for: Block pool
> BP-1775344991-172.17.0.2-1504116157738 (Datanode Uuid
> d7ee1847-d046-47ea-9a05-7fd25bcb1e86) service to localhost/127.0.0.1:47551
> 2017-08-30 18:02:49,404 [BP-1775344991-172.17.0.2-1504116157738 heartbeating
> to localhost/127.0.0.1:47551] INFO datanode.DataNode
> (BlockPoolManager.java:remove(102)) - Removed Block pool
> BP-1775344991-172.17.0.2-1504116157738 (Datanode Uuid
> d7ee1847-d046-47ea-9a05-7fd25bcb1e86)
> 2017-08-30 18:02:49,404 [BP-1775344991-172.17.0.2-1504116157738 heartbeating
> to localhost/127.0.0.1:47551] INFO impl.FsDatasetImpl
> (FsDatasetImpl.java:shutdownBlockPool(2675)) - Removing block pool
> BP-1775344991-172.17.0.2-1504116157738
> 2017-08-30 18:02:49,405
> [refreshUsed-/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data1/current/BP-1775344991-172.17.0.2-1504116157738]
> WARN fs.CachingGetSpaceUsed (CachingGetSpaceUsed.java:run(183)) - Thread
> Interrupted waiting to refresh disk information: sleep interrupted
> 2017-08-30 18:02:49,405
> [refreshUsed-/testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/data/data2/current/BP-1775344991-172.17.0.2-1504116157738]
> WARN fs.CachingGetSpaceUsed (CachingGetSpaceUsed.java:run(183)) - Thread
> Interrupted waiting to refresh disk information: sleep interrupted
> 2017-08-30 18:02:49,406 [main] INFO impl.FsDatasetAsyncDiskService
> (FsDatasetAsyncDiskService.java:shutdown(191)) - Shutting down all async disk
> service threads
> 2017-08-30 18:02:49,406 [main] INFO impl.FsDatasetAsyncDiskService
> (FsDatasetAsyncDiskService.java:shutdown(199)) - All async disk service
> threads have been shut down
> 2017-08-30 18:02:49,406 [main] INFO impl.RamDiskAsyncLazyPersistService
> (RamDiskAsyncLazyPersistService.java:shutdown(176)) - Shutting down all async
> lazy persist service threads
> 2017-08-30 18:02:49,407 [main] INFO impl.RamDiskAsyncLazyPersistService
> (RamDiskAsyncLazyPersistService.java:shutdown(183)) - All async lazy persist
> service threads have been shut down
> 2017-08-30 18:02:49,407 [main] INFO datanode.DataNode
> (DataNode.java:shutdown(2109)) - Shutdown complete.
> 2017-08-30 18:02:49,407 [main] INFO hdfs.MiniDFSCluster
> (MiniDFSCluster.java:stopAndJoinNameNode(2038)) - Shutting down the namenode
> 2017-08-30 18:02:49,407 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:stopActiveServices(1301)) - Stopping services started for
> active state
> 2017-08-30 18:02:49,408 [main] INFO namenode.FSEditLog
> (FSEditLog.java:endCurrentLogSegment(1369)) - Ending log segment 1, 8
> 2017-08-30 18:02:49,408
> [org.apache.hadoop.hdfs.server.namenode.FSNamesystem$LazyPersistFileScrubber@ef1695a]
> INFO namenode.FSNamesystem (FSNamesystem.java:run(3985)) -
> LazyPersistFileScrubber was interrupted, exiting
> 2017-08-30 18:02:49,408
> [org.apache.hadoop.hdfs.server.namenode.FSNamesystem$NameNodeEditLogRoller@238bfd6c]
> INFO namenode.FSNamesystem (FSNamesystem.java:run(3894)) -
> NameNodeEditLogRoller was interrupted, exiting
> 2017-08-30 18:02:49,408 [main] INFO namenode.FSEditLog
> (FSEditLog.java:logSyncAll(600)) - logSyncAll toSyncToTxId=9 lastSyncedTxid=8
> mostRecentTxid=9
> 2017-08-30 18:02:49,408 [main] INFO namenode.FSEditLog
> (FSEditLog.java:logSyncAll(605)) - Done logSyncAll lastWrittenTxId=9
> lastSyncedTxid=9 mostRecentTxid=9
> 2017-08-30 18:02:49,408 [main] INFO namenode.FSEditLog
> (FSEditLog.java:printStatistics(770)) - Number of transactions: 9 Total time
> for transactions(ms): 3 Number of transactions batched in Syncs: 4 Number of
> syncs: 6 SyncTimes(ms): 2 1
> 2017-08-30 18:02:49,409 [main] INFO namenode.FileJournalManager
> (FileJournalManager.java:finalizeLogSegment(143)) - Finalizing edits file
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/name-0-1/current/edits_inprogress_0000000000000000001
> ->
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/name-0-1/current/edits_0000000000000000001-0000000000000000009
> 2017-08-30 18:02:49,410 [main] INFO namenode.FileJournalManager
> (FileJournalManager.java:finalizeLogSegment(143)) - Finalizing edits file
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/name-0-2/current/edits_inprogress_0000000000000000001
> ->
> /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test/data/3/dfs/name-0-2/current/edits_0000000000000000001-0000000000000000009
> 2017-08-30 18:02:49,410 [CacheReplicationMonitor(1864849826)] INFO
> blockmanagement.CacheReplicationMonitor
> (CacheReplicationMonitor.java:run(169)) - Shutting down
> CacheReplicationMonitor
> 2017-08-30 18:02:49,411 [main] INFO ipc.Server (Server.java:stop(3074)) -
> Stopping server on 47551
> 2017-08-30 18:02:49,412 [IPC Server listener on 47551] INFO ipc.Server
> (Server.java:run(1178)) - Stopping IPC Server listener on 47551
> 2017-08-30 18:02:49,414 [IPC Server Responder] INFO ipc.Server
> (Server.java:run(1312)) - Stopping IPC Server Responder
> 2017-08-30 18:02:49,415 [StorageInfoMonitor] INFO
> blockmanagement.BlockManager (BlockManager.java:run(4450)) - Stopping thread.
> 2017-08-30 18:02:49,415 [RedundancyMonitor] INFO
> blockmanagement.BlockManager (BlockManager.java:run(4415)) - Stopping
> RedundancyMonitor.
> 2017-08-30 18:02:49,422 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:stopActiveServices(1301)) - Stopping services started for
> active state
> 2017-08-30 18:02:49,423 [main] INFO namenode.FSNamesystem
> (FSNamesystem.java:stopStandbyServices(1397)) - Stopping services started for
> standby state
> 2017-08-30 18:02:49,424 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStop(910)) - Stopped
> o.e.j.w.WebAppContext@5633dafd{/,null,UNAVAILABLE}{/hdfs}
> 2017-08-30 18:02:49,425 [main] INFO server.AbstractConnector
> (AbstractConnector.java:doStop(318)) - Stopped
> ServerConnector@5d5160e6{HTTP/1.1,[http/1.1]}{localhost:0}
> 2017-08-30 18:02:49,425 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStop(910)) - Stopped
> o.e.j.s.ServletContextHandler@5e8cda75{/static,file:///testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/test-classes/webapps/static/,UNAVAILABLE}
> 2017-08-30 18:02:49,425 [main] INFO handler.ContextHandler
> (ContextHandler.java:doStop(910)) - Stopped
> o.e.j.s.ServletContextHandler@46c3a14d{/logs,file:///testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs/target/log/,UNAVAILABLE}
> 2017-08-30 18:02:49,426 [main] INFO impl.MetricsSystemImpl
> (MetricsSystemImpl.java:stop(210)) - Stopping DataNode metrics system...
> 2017-08-30 18:02:49,428 [main] INFO impl.MetricsSystemImpl
> (MetricsSystemImpl.java:stop(216)) - DataNode metrics system stopped.
> 2017-08-30 18:02:49,428 [main] INFO impl.MetricsSystemImpl
> (MetricsSystemImpl.java:shutdown(607)) - DataNode metrics system shutdown
> complete.
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
