[
https://issues.apache.org/jira/browse/HDFS-15643?focusedWorklogId=505243&page=com.atlassian.jira.plugin.system.issuetabpanels:worklog-tabpanel#worklog-505243
]
ASF GitHub Bot logged work on HDFS-15643:
-----------------------------------------
Author: ASF GitHub Bot
Created on: 27/Oct/20 14:21
Start Date: 27/Oct/20 14:21
Worklog Time Spent: 10m
Work Description: amahussein commented on pull request #2408:
URL: https://github.com/apache/hadoop/pull/2408#issuecomment-717278256
> hadoop.hdfs.TestFileChecksumCompositeCrc and hadoop.hdfs.TestFileChecksum
are still failing, are the failures related to the patch?
Thank you Akira.
It is not due to the patch. Probably, it needs some configurations to set
the timeouts of the pending reconstruction blocks. I will investigate the stack
and see if I can fix it.
```bash
org.apache.hadoop.hdfs.TestFileChecksumCompositeCrc.testStripedFileChecksumWithMissedDataBlocksRangeQuery15
Error Details
`/striped/stripedFileChecksum1': Fail to get block checksum for
LocatedStripedBlock{BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775792_1001;
getBlockSize()=37748736; corrupt=false; offset=0;
locs=[DatanodeInfoWithStorage[127.0.0.1:41259,DS-211baa4b-9658-4792-9eb9-971650316b65,DISK],
DatanodeInfoWithStorage[127.0.0.1:42903,DS-c7b78dc0-e09e-4368-bc48-7e2d148acb2f,DISK],
DatanodeInfoWithStorage[127.0.0.1:35419,DS-4697e810-71cb-44b4-a4f0-e8c105a0d30b,DISK],
DatanodeInfoWithStorage[127.0.0.1:39685,DS-c210f999-d67c-490d-b675-e286b0abd6ee,DISK],
DatanodeInfoWithStorage[127.0.0.1:44039,DS-51a33914-b87e-43ef-ae14-13caa38ff319,DISK],
DatanodeInfoWithStorage[127.0.0.1:39239,DS-e9764209-9d9c-4f2f-843c-183cb415a2ec,DISK],
DatanodeInfoWithStorage[127.0.0.1:35165,DS-9b8fb76f-5d5f-412e-b148-c482489342d9,DISK],
DatanodeInfoWithStorage[127.0.0.1:44431,DS-dc88f6f1-a3e5-407e-84a7-6e455bb6fdd1,DISK]];
indices=[0, 1, 2, 3, 4, 6, 7, 8]}
Stack Trace
org.apache.hadoop.fs.PathIOException: `/striped/stripedFileChecksum1': Fail
to get block checksum for
LocatedStripedBlock{BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775792_1001;
getBlockSize()=37748736; corrupt=false; offset=0;
locs=[DatanodeInfoWithStorage[127.0.0.1:41259,DS-211baa4b-9658-4792-9eb9-971650316b65,DISK],
DatanodeInfoWithStorage[127.0.0.1:42903,DS-c7b78dc0-e09e-4368-bc48-7e2d148acb2f,DISK],
DatanodeInfoWithStorage[127.0.0.1:35419,DS-4697e810-71cb-44b4-a4f0-e8c105a0d30b,DISK],
DatanodeInfoWithStorage[127.0.0.1:39685,DS-c210f999-d67c-490d-b675-e286b0abd6ee,DISK],
DatanodeInfoWithStorage[127.0.0.1:44039,DS-51a33914-b87e-43ef-ae14-13caa38ff319,DISK],
DatanodeInfoWithStorage[127.0.0.1:39239,DS-e9764209-9d9c-4f2f-843c-183cb415a2ec,DISK],
DatanodeInfoWithStorage[127.0.0.1:35165,DS-9b8fb76f-5d5f-412e-b148-c482489342d9,DISK],
DatanodeInfoWithStorage[127.0.0.1:44431,DS-dc88f6f1-a3e5-407e-84a7-6e455bb6fdd1,DISK]];
indices=[0, 1, 2, 3, 4, 6, 7, 8]}
at
org.apache.hadoop.hdfs.FileChecksumHelper$StripedFileNonStripedChecksumComputer.checksumBlocks(FileChecksumHelper.java:640)
at
org.apache.hadoop.hdfs.FileChecksumHelper$FileChecksumComputer.compute(FileChecksumHelper.java:252)
at
org.apache.hadoop.hdfs.DFSClient.getFileChecksumInternal(DFSClient.java:1851)
at
org.apache.hadoop.hdfs.DFSClient.getFileChecksumWithCombineMode(DFSClient.java:1871)
at
org.apache.hadoop.hdfs.DistributedFileSystem$34.doCall(DistributedFileSystem.java:1903)
at
org.apache.hadoop.hdfs.DistributedFileSystem$34.doCall(DistributedFileSystem.java:1900)
at
org.apache.hadoop.fs.FileSystemLinkResolver.resolve(FileSystemLinkResolver.java:81)
at
org.apache.hadoop.hdfs.DistributedFileSystem.getFileChecksum(DistributedFileSystem.java:1917)
at
org.apache.hadoop.hdfs.TestFileChecksum.getFileChecksum(TestFileChecksum.java:592)
at
org.apache.hadoop.hdfs.TestFileChecksum.testStripedFileChecksumWithMissedDataBlocksRangeQuery(TestFileChecksum.java:306)
at
org.apache.hadoop.hdfs.TestFileChecksum.testStripedFileChecksumWithMissedDataBlocksRangeQuery15(TestFileChecksum.java:476)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at
org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at
org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at
org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
at
org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:298)
at
org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:292)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.lang.Thread.run(Thread.java:748)
Standard Output
2020-10-23 22:41:06,342 [Listener at localhost/37463] INFO
hdfs.MiniDFSCluster (MiniDFSCluster.java:<init>(529)) - starting cluster:
numNameNodes=1, numDataNodes=11
2020-10-23 22:41:06,345 [Listener at localhost/37463] INFO
namenode.NameNode (NameNode.java:format(1249)) - Formatting using clusterid:
testClusterID
2020-10-23 22:41:06,345 [Listener at localhost/37463] INFO
namenode.FSEditLog (FSEditLog.java:newInstance(229)) - Edit logging is
async:true
2020-10-23 22:41:06,354 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystem.java:<init>(828)) - KeyProvider: null
2020-10-23 22:41:06,354 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystemLock.java:<init>(131)) - fsLock is fair: true
2020-10-23 22:41:06,354 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystemLock.java:<init>(149)) - Detailed lock hold
time metrics enabled: false
2020-10-23 22:41:06,355 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystem.java:<init>(861)) - fsOwner
= jenkins (auth:SIMPLE)
2020-10-23 22:41:06,355 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystem.java:<init>(862)) - supergroup
= supergroup
2020-10-23 22:41:06,355 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystem.java:<init>(863)) - isPermissionEnabled
= true
2020-10-23 22:41:06,355 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystem.java:<init>(864)) - isStoragePolicyEnabled
= true
2020-10-23 22:41:06,355 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystem.java:<init>(875)) - HA Enabled: false
2020-10-23 22:41:06,356 [Listener at localhost/37463] INFO common.Util
(Util.java:isDiskStatsEnabled(395)) -
dfs.datanode.fileio.profiling.sampling.percentage set to 0. Disabling file IO
profiling
2020-10-23 22:41:06,356 [Listener at localhost/37463] INFO
blockmanagement.DatanodeManager (DatanodeManager.java:<init>(310)) -
dfs.block.invalidate.limit: configured=1000, counted=60, effected=1000
2020-10-23 22:41:06,356 [Listener at localhost/37463] INFO
blockmanagement.DatanodeManager (DatanodeManager.java:<init>(318)) -
dfs.namenode.datanode.registration.ip-hostname-check=true
2020-10-23 22:41:06,356 [Listener at localhost/37463] INFO
blockmanagement.BlockManager (InvalidateBlocks.java:printBlockDeletionTime(77))
- dfs.namenode.startup.delay.block.deletion.sec is set to 000:00:00:00.000
2020-10-23 22:41:06,357 [Listener at localhost/37463] INFO
blockmanagement.BlockManager (InvalidateBlocks.java:printBlockDeletionTime(83))
- The block deletion will start around 2020 Oct 23 22:41:06
2020-10-23 22:41:06,357 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
BlocksMap
2020-10-23 22:41:06,357 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
2020-10-23 22:41:06,357 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(397)) - 2.0% max memory 1.9 GB = 38.8 MB
2020-10-23 22:41:06,357 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(402)) - capacity = 2^22 = 4194304
entries
2020-10-23 22:41:06,360 [Listener at localhost/37463] INFO
blockmanagement.BlockManager (BlockManager.java:createSPSManager(5439)) -
Storage policy satisfier is disabled
2020-10-23 22:41:06,361 [Listener at localhost/37463] INFO
blockmanagement.BlockManager
(BlockManager.java:createBlockTokenSecretManager(641)) -
dfs.block.access.token.enable = true
2020-10-23 22:41:06,361 [Listener at localhost/37463] INFO
blockmanagement.BlockManager
(BlockManager.java:createBlockTokenSecretManager(663)) -
dfs.block.access.key.update.interval=600 min(s),
dfs.block.access.token.lifetime=600 min(s),
dfs.encrypt.data.transfer.algorithm=null
2020-10-23 22:41:06,361 [Listener at localhost/37463] INFO
block.BlockTokenSecretManager (BlockTokenSecretManager.java:<init>(154)) -
Block token key range: [0, 2147483647)
2020-10-23 22:41:06,362 [Listener at localhost/37463] INFO
blockmanagement.BlockManagerSafeMode (BlockManagerSafeMode.java:<init>(160)) -
dfs.namenode.safemode.threshold-pct = 0.999
2020-10-23 22:41:06,362 [Listener at localhost/37463] INFO
blockmanagement.BlockManagerSafeMode (BlockManagerSafeMode.java:<init>(161)) -
dfs.namenode.safemode.min.datanodes = 0
2020-10-23 22:41:06,362 [Listener at localhost/37463] INFO
blockmanagement.BlockManagerSafeMode (BlockManagerSafeMode.java:<init>(163)) -
dfs.namenode.safemode.extension = 0
2020-10-23 22:41:06,362 [Listener at localhost/37463] INFO
blockmanagement.BlockManager (BlockManager.java:<init>(627)) -
defaultReplication = 3
2020-10-23 22:41:06,362 [Listener at localhost/37463] INFO
blockmanagement.BlockManager (BlockManager.java:<init>(628)) - maxReplication
= 512
2020-10-23 22:41:06,362 [Listener at localhost/37463] INFO
blockmanagement.BlockManager (BlockManager.java:<init>(629)) - minReplication
= 1
2020-10-23 22:41:06,362 [Listener at localhost/37463] INFO
blockmanagement.BlockManager (BlockManager.java:<init>(630)) -
maxReplicationStreams = 0
2020-10-23 22:41:06,362 [Listener at localhost/37463] INFO
blockmanagement.BlockManager (BlockManager.java:<init>(631)) -
redundancyRecheckInterval = 3000ms
2020-10-23 22:41:06,363 [Listener at localhost/37463] INFO
blockmanagement.BlockManager (BlockManager.java:<init>(632)) -
encryptDataTransfer = false
2020-10-23 22:41:06,363 [Listener at localhost/37463] INFO
blockmanagement.BlockManager (BlockManager.java:<init>(633)) -
maxNumBlocksToLog = 1000
2020-10-23 22:41:06,363 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
INodeMap
2020-10-23 22:41:06,363 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
2020-10-23 22:41:06,364 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(397)) - 1.0% max memory 1.9 GB = 19.4 MB
2020-10-23 22:41:06,364 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(402)) - capacity = 2^21 = 2097152
entries
2020-10-23 22:41:06,366 [Listener at localhost/37463] INFO
namenode.FSDirectory (FSDirectory.java:<init>(335)) - ACLs enabled? true
2020-10-23 22:41:06,366 [Listener at localhost/37463] INFO
namenode.FSDirectory (FSDirectory.java:<init>(339)) - POSIX ACL inheritance
enabled? true
2020-10-23 22:41:06,366 [Listener at localhost/37463] INFO
namenode.FSDirectory (FSDirectory.java:<init>(343)) - XAttrs enabled? true
2020-10-23 22:41:06,366 [Listener at localhost/37463] INFO
namenode.NameNode (FSDirectory.java:<init>(406)) - Caching file names occurring
more than 10 times
2020-10-23 22:41:06,366 [Listener at localhost/37463] INFO
snapshot.SnapshotManager (SnapshotManager.java:<init>(162)) - Loaded config
captureOpenFiles: false, skipCaptureAccessTimeOnlyChange: false,
snapshotDiffAllowSnapRootDescendant: true, maxSnapshotFSLimit: 65536,
maxSnapshotLimit: 65536
2020-10-23 22:41:06,367 [Listener at localhost/37463] INFO
snapshot.SnapshotManager (SnapshotManager.java:<init>(175)) -
dfs.namenode.snapshot.deletion.ordered = false
2020-10-23 22:41:06,367 [Listener at localhost/37463] INFO
snapshot.SnapshotManager (DirectoryDiffListFactory.java:init(43)) - SkipList is
disabled
2020-10-23 22:41:06,367 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
cachedBlocks
2020-10-23 22:41:06,367 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
2020-10-23 22:41:06,368 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(397)) - 0.25% max memory 1.9 GB = 4.8 MB
2020-10-23 22:41:06,368 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(402)) - capacity = 2^19 = 524288
entries
2020-10-23 22:41:06,368 [Listener at localhost/37463] INFO
metrics.TopMetrics (TopMetrics.java:logConf(76)) - NNTop conf:
dfs.namenode.top.window.num.buckets = 10
2020-10-23 22:41:06,369 [Listener at localhost/37463] INFO
metrics.TopMetrics (TopMetrics.java:logConf(78)) - NNTop conf:
dfs.namenode.top.num.users = 10
2020-10-23 22:41:06,369 [Listener at localhost/37463] INFO
metrics.TopMetrics (TopMetrics.java:logConf(80)) - NNTop conf:
dfs.namenode.top.windows.minutes = 1,5,25
2020-10-23 22:41:06,369 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystem.java:initRetryCache(1105)) - Retry cache on
namenode is enabled
2020-10-23 22:41:06,369 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystem.java:initRetryCache(1113)) - Retry cache
will use 0.03 of total heap and retry cache entry expiry time is 600000 millis
2020-10-23 22:41:06,370 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
NameNodeRetryCache
2020-10-23 22:41:06,370 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
2020-10-23 22:41:06,370 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(397)) - 0.029999999329447746% max memory
1.9 GB = 595.2 KB
2020-10-23 22:41:06,370 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(402)) - capacity = 2^16 = 65536
entries
2020-10-23 22:41:06,371 [Listener at localhost/37463] INFO namenode.FSImage
(FSImage.java:format(185)) - Allocated new BlockPoolId:
BP-1233294053-172.17.0.2-1603492866371
2020-10-23 22:41:06,466 [Listener at localhost/37463] INFO common.Storage
(NNStorage.java:format(595)) - Storage directory
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/name-0-1
has been successfully formatted.
2020-10-23 22:41:06,543 [Listener at localhost/37463] INFO common.Storage
(NNStorage.java:format(595)) - Storage directory
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/name-0-2
has been successfully formatted.
2020-10-23 22:41:06,557 [FSImageSaver for
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/name-0-2
of type IMAGE_AND_EDITS] INFO namenode.FSImageFormatProtobuf
(FSImageFormatProtobuf.java:save(717)) - Saving image file
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/name-0-2/current/fsimage.ckpt_0000000000000000000
using no compression
2020-10-23 22:41:06,559 [FSImageSaver for
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/name-0-1
of type IMAGE_AND_EDITS] INFO namenode.FSImageFormatProtobuf
(FSImageFormatProtobuf.java:save(717)) - Saving image file
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/name-0-1/current/fsimage.ckpt_0000000000000000000
using no compression
2020-10-23 22:41:06,583 [FSImageSaver for
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/name-0-2
of type IMAGE_AND_EDITS] INFO namenode.FSImageFormatProtobuf
(FSImageFormatProtobuf.java:save(721)) - Image file
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/name-0-2/current/fsimage.ckpt_0000000000000000000
of size 454 bytes saved in 0 seconds .
2020-10-23 22:41:06,583 [FSImageSaver for
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/name-0-1
of type IMAGE_AND_EDITS] INFO namenode.FSImageFormatProtobuf
(FSImageFormatProtobuf.java:save(721)) - Image file
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/name-0-1/current/fsimage.ckpt_0000000000000000000
of size 454 bytes saved in 0 seconds .
2020-10-23 22:41:06,638 [Listener at localhost/37463] INFO
namenode.NNStorageRetentionManager
(NNStorageRetentionManager.java:getImageTxIdToRetain(203)) - Going to retain 1
images with txid >= 0
2020-10-23 22:41:06,639 [Listener at localhost/37463] INFO
namenode.NameNode (NameNode.java:createNameNode(1700)) - createNameNode []
2020-10-23 22:41:06,642 [Listener at localhost/37463] INFO
impl.MetricsConfig (MetricsConfig.java:loadFirst(120)) - Loaded properties from
hadoop-metrics2.properties
2020-10-23 22:41:06,649 [Listener at localhost/37463] INFO
impl.MetricsSystemImpl (MetricsSystemImpl.java:startTimer(378)) - Scheduled
Metric snapshot period at 0 second(s).
2020-10-23 22:41:06,649 [Listener at localhost/37463] INFO
impl.MetricsSystemImpl (MetricsSystemImpl.java:start(191)) - NameNode metrics
system started
2020-10-23 22:41:06,651 [Listener at localhost/37463] INFO
namenode.NameNodeUtils (NameNodeUtils.java:getClientNamenodeAddress(79)) -
fs.defaultFS is hdfs://127.0.0.1:0
2020-10-23 22:41:06,666
[org.apache.hadoop.util.JvmPauseMonitor$Monitor@6d6bff89] INFO
util.JvmPauseMonitor (JvmPauseMonitor.java:run(188)) - Starting JVM pause
monitor
2020-10-23 22:41:06,668 [Listener at localhost/37463] INFO hdfs.DFSUtil
(DFSUtil.java:httpServerTemplateForNNAndJN(1668)) - Filter initializers set :
org.apache.hadoop.http.lib.StaticUserWebFilter,org.apache.hadoop.hdfs.web.AuthFilterInitializer
2020-10-23 22:41:06,669 [Listener at localhost/37463] INFO hdfs.DFSUtil
(DFSUtil.java:httpServerTemplateForNNAndJN(1690)) - Starting Web-server for
hdfs at: http://localhost:0
2020-10-23 22:41:06,669 [Listener at localhost/37463] INFO http.HttpServer2
(HttpServer2.java:getWebAppsPath(1141)) - Web server is in development mode.
Resources will be read from the source tree.
2020-10-23 22:41:06,671 [Listener at localhost/37463] INFO
server.AuthenticationFilter
(AuthenticationFilter.java:constructSecretProvider(240)) - Unable to initialize
FileSignerSecretProvider, falling back to use random secrets.
2020-10-23 22:41:06,672 [Listener at localhost/37463] INFO
http.HttpRequestLog (HttpRequestLog.java:getRequestLog(82)) - Http request log
for http.requests.namenode is not defined
2020-10-23 22:41:06,672 [Listener at localhost/37463] INFO http.HttpServer2
(HttpServer2.java:getWebAppsPath(1141)) - Web server is in development mode.
Resources will be read from the source tree.
2020-10-23 22:41:06,674 [Listener at localhost/37463] INFO http.HttpServer2
(HttpServer2.java:addGlobalFilter(1059)) - Added global filter 'safety'
(class=org.apache.hadoop.http.HttpServer2$QuotingInputFilter)
2020-10-23 22:41:06,675 [Listener at localhost/37463] INFO http.HttpServer2
(HttpServer2.java:addFilter(1032)) - Added filter static_user_filter
(class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
context hdfs
2020-10-23 22:41:06,675 [Listener at localhost/37463] INFO http.HttpServer2
(HttpServer2.java:addFilter(1042)) - Added filter static_user_filter
(class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
context logs
2020-10-23 22:41:06,675 [Listener at localhost/37463] INFO http.HttpServer2
(HttpServer2.java:addFilter(1042)) - Added filter static_user_filter
(class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
context static
2020-10-23 22:41:06,677 [Listener at localhost/37463] INFO http.HttpServer2
(HttpServer2.java:addFilter(1032)) - Added filter AuthFilter
(class=org.apache.hadoop.hdfs.web.AuthFilter) to context hdfs
2020-10-23 22:41:06,677 [Listener at localhost/37463] INFO http.HttpServer2
(HttpServer2.java:addFilter(1042)) - Added filter AuthFilter
(class=org.apache.hadoop.hdfs.web.AuthFilter) to context logs
2020-10-23 22:41:06,677 [Listener at localhost/37463] INFO http.HttpServer2
(HttpServer2.java:addFilter(1042)) - Added filter AuthFilter
(class=org.apache.hadoop.hdfs.web.AuthFilter) to context static
2020-10-23 22:41:06,678 [Listener at localhost/37463] INFO http.HttpServer2
(HttpServer2.java:addJerseyResourcePackage(886)) - addJerseyResourcePackage:
packageName=org.apache.hadoop.hdfs.server.namenode.web.resources;org.apache.hadoop.hdfs.web.resources,
pathSpec=/webhdfs/v1/*
2020-10-23 22:41:06,679 [Listener at localhost/37463] INFO http.HttpServer2
(HttpServer2.java:bindListener(1280)) - Jetty bound to port 42767
2020-10-23 22:41:06,679 [Listener at localhost/37463] INFO server.Server
(Server.java:doStart(359)) - jetty-9.4.20.v20190813; built:
2019-08-13T21:28:18.144Z; git: 84700530e645e812b336747464d6fbbf370c9a20; jvm
1.8.0_265-8u265-b01-0ubuntu2~18.04-b01
2020-10-23 22:41:06,693 [Listener at localhost/37463] INFO server.session
(DefaultSessionIdManager.java:doStart(333)) - DefaultSessionIdManager
workerName=node0
2020-10-23 22:41:06,693 [Listener at localhost/37463] INFO server.session
(DefaultSessionIdManager.java:doStart(338)) - No SessionScavenger set, using
defaults
2020-10-23 22:41:06,693 [Listener at localhost/37463] INFO server.session
(HouseKeeper.java:startScavenging(140)) - node0 Scavenging every 600000ms
2020-10-23 22:41:06,695 [Listener at localhost/37463] INFO
server.AuthenticationFilter
(AuthenticationFilter.java:constructSecretProvider(240)) - Unable to initialize
FileSignerSecretProvider, falling back to use random secrets.
2020-10-23 22:41:06,696 [Listener at localhost/37463] INFO
handler.ContextHandler (ContextHandler.java:doStart(824)) - Started
o.e.j.s.ServletContextHandler@61149fa5{logs,/logs,file:///home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/log/,AVAILABLE}
2020-10-23 22:41:06,696 [Listener at localhost/37463] INFO
handler.ContextHandler (ContextHandler.java:doStart(824)) - Started
o.e.j.s.ServletContextHandler@f2d890c{static,/static,file:///home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/src/main/webapps/static/,AVAILABLE}
2020-10-23 22:41:06,703 [Listener at localhost/37463] INFO
handler.ContextHandler (ContextHandler.java:doStart(824)) - Started
o.e.j.w.WebAppContext@236fdf{hdfs,/,file:///home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/src/main/webapps/hdfs/,AVAILABLE}{file:/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/src/main/webapps/hdfs}
2020-10-23 22:41:06,706 [Listener at localhost/37463] INFO
server.AbstractConnector (AbstractConnector.java:doStart(293)) - Started
ServerConnector@49c099b{HTTP/1.1,[http/1.1]}{localhost:42767}
2020-10-23 22:41:06,706 [Listener at localhost/37463] INFO server.Server
(Server.java:doStart(399)) - Started @61146ms
2020-10-23 22:41:06,708 [Listener at localhost/37463] INFO
namenode.FSEditLog (FSEditLog.java:newInstance(229)) - Edit logging is
async:true
2020-10-23 22:41:06,720 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystem.java:<init>(828)) - KeyProvider: null
2020-10-23 22:41:06,720 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystemLock.java:<init>(131)) - fsLock is fair: true
2020-10-23 22:41:06,721 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystemLock.java:<init>(149)) - Detailed lock hold
time metrics enabled: false
2020-10-23 22:41:06,721 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystem.java:<init>(861)) - fsOwner
= jenkins (auth:SIMPLE)
2020-10-23 22:41:06,721 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystem.java:<init>(862)) - supergroup
= supergroup
2020-10-23 22:41:06,721 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystem.java:<init>(863)) - isPermissionEnabled
= true
2020-10-23 22:41:06,721 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystem.java:<init>(864)) - isStoragePolicyEnabled
= true
2020-10-23 22:41:06,722 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystem.java:<init>(875)) - HA Enabled: false
2020-10-23 22:41:06,722 [Listener at localhost/37463] INFO common.Util
(Util.java:isDiskStatsEnabled(395)) -
dfs.datanode.fileio.profiling.sampling.percentage set to 0. Disabling file IO
profiling
2020-10-23 22:41:06,722 [Listener at localhost/37463] INFO
blockmanagement.DatanodeManager (DatanodeManager.java:<init>(310)) -
dfs.block.invalidate.limit: configured=1000, counted=60, effected=1000
2020-10-23 22:41:06,723 [Listener at localhost/37463] INFO
blockmanagement.DatanodeManager (DatanodeManager.java:<init>(318)) -
dfs.namenode.datanode.registration.ip-hostname-check=true
2020-10-23 22:41:06,723 [Listener at localhost/37463] INFO
blockmanagement.BlockManager (InvalidateBlocks.java:printBlockDeletionTime(77))
- dfs.namenode.startup.delay.block.deletion.sec is set to 000:00:00:00.000
2020-10-23 22:41:06,724 [Listener at localhost/37463] INFO
blockmanagement.BlockManager (InvalidateBlocks.java:printBlockDeletionTime(83))
- The block deletion will start around 2020 Oct 23 22:41:06
2020-10-23 22:41:06,724 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
BlocksMap
2020-10-23 22:41:06,724 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
2020-10-23 22:41:06,724 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(397)) - 2.0% max memory 1.9 GB = 38.8 MB
2020-10-23 22:41:06,725 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(402)) - capacity = 2^22 = 4194304
entries
2020-10-23 22:41:06,728 [Listener at localhost/37463] INFO
blockmanagement.BlockManager (BlockManager.java:createSPSManager(5439)) -
Storage policy satisfier is disabled
2020-10-23 22:41:06,728 [Listener at localhost/37463] INFO
blockmanagement.BlockManager
(BlockManager.java:createBlockTokenSecretManager(641)) -
dfs.block.access.token.enable = true
2020-10-23 22:41:06,728 [Listener at localhost/37463] INFO
blockmanagement.BlockManager
(BlockManager.java:createBlockTokenSecretManager(663)) -
dfs.block.access.key.update.interval=600 min(s),
dfs.block.access.token.lifetime=600 min(s),
dfs.encrypt.data.transfer.algorithm=null
2020-10-23 22:41:06,729 [Listener at localhost/37463] INFO
block.BlockTokenSecretManager (BlockTokenSecretManager.java:<init>(154)) -
Block token key range: [0, 2147483647)
2020-10-23 22:41:06,729 [Listener at localhost/37463] INFO
blockmanagement.BlockManagerSafeMode (BlockManagerSafeMode.java:<init>(160)) -
dfs.namenode.safemode.threshold-pct = 0.999
2020-10-23 22:41:06,729 [Listener at localhost/37463] INFO
blockmanagement.BlockManagerSafeMode (BlockManagerSafeMode.java:<init>(161)) -
dfs.namenode.safemode.min.datanodes = 0
2020-10-23 22:41:06,730 [Listener at localhost/37463] INFO
blockmanagement.BlockManagerSafeMode (BlockManagerSafeMode.java:<init>(163)) -
dfs.namenode.safemode.extension = 0
2020-10-23 22:41:06,730 [Listener at localhost/37463] INFO
blockmanagement.BlockManager (BlockManager.java:<init>(627)) -
defaultReplication = 3
2020-10-23 22:41:06,730 [Listener at localhost/37463] INFO
blockmanagement.BlockManager (BlockManager.java:<init>(628)) - maxReplication
= 512
2020-10-23 22:41:06,730 [Listener at localhost/37463] INFO
blockmanagement.BlockManager (BlockManager.java:<init>(629)) - minReplication
= 1
2020-10-23 22:41:06,730 [Listener at localhost/37463] INFO
blockmanagement.BlockManager (BlockManager.java:<init>(630)) -
maxReplicationStreams = 0
2020-10-23 22:41:06,730 [Listener at localhost/37463] INFO
blockmanagement.BlockManager (BlockManager.java:<init>(631)) -
redundancyRecheckInterval = 3000ms
2020-10-23 22:41:06,731 [Listener at localhost/37463] INFO
blockmanagement.BlockManager (BlockManager.java:<init>(632)) -
encryptDataTransfer = false
2020-10-23 22:41:06,731 [Listener at localhost/37463] INFO
blockmanagement.BlockManager (BlockManager.java:<init>(633)) -
maxNumBlocksToLog = 1000
2020-10-23 22:41:06,731 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
INodeMap
2020-10-23 22:41:06,731 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
2020-10-23 22:41:06,732 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(397)) - 1.0% max memory 1.9 GB = 19.4 MB
2020-10-23 22:41:06,732 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(402)) - capacity = 2^21 = 2097152
entries
2020-10-23 22:41:06,734 [Listener at localhost/37463] INFO
namenode.FSDirectory (FSDirectory.java:<init>(335)) - ACLs enabled? true
2020-10-23 22:41:06,734 [Listener at localhost/37463] INFO
namenode.FSDirectory (FSDirectory.java:<init>(339)) - POSIX ACL inheritance
enabled? true
2020-10-23 22:41:06,734 [Listener at localhost/37463] INFO
namenode.FSDirectory (FSDirectory.java:<init>(343)) - XAttrs enabled? true
2020-10-23 22:41:06,734 [Listener at localhost/37463] INFO
namenode.NameNode (FSDirectory.java:<init>(406)) - Caching file names occurring
more than 10 times
2020-10-23 22:41:06,734 [Listener at localhost/37463] INFO
snapshot.SnapshotManager (SnapshotManager.java:<init>(162)) - Loaded config
captureOpenFiles: false, skipCaptureAccessTimeOnlyChange: false,
snapshotDiffAllowSnapRootDescendant: true, maxSnapshotFSLimit: 65536,
maxSnapshotLimit: 65536
2020-10-23 22:41:06,735 [Listener at localhost/37463] INFO
snapshot.SnapshotManager (SnapshotManager.java:<init>(175)) -
dfs.namenode.snapshot.deletion.ordered = false
2020-10-23 22:41:06,735 [Listener at localhost/37463] INFO
snapshot.SnapshotManager (DirectoryDiffListFactory.java:init(43)) - SkipList is
disabled
2020-10-23 22:41:06,735 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
cachedBlocks
2020-10-23 22:41:06,735 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
2020-10-23 22:41:06,736 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(397)) - 0.25% max memory 1.9 GB = 4.8 MB
2020-10-23 22:41:06,736 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(402)) - capacity = 2^19 = 524288
entries
2020-10-23 22:41:06,737 [Listener at localhost/37463] INFO
metrics.TopMetrics (TopMetrics.java:logConf(76)) - NNTop conf:
dfs.namenode.top.window.num.buckets = 10
2020-10-23 22:41:06,737 [Listener at localhost/37463] INFO
metrics.TopMetrics (TopMetrics.java:logConf(78)) - NNTop conf:
dfs.namenode.top.num.users = 10
2020-10-23 22:41:06,737 [Listener at localhost/37463] INFO
metrics.TopMetrics (TopMetrics.java:logConf(80)) - NNTop conf:
dfs.namenode.top.windows.minutes = 1,5,25
2020-10-23 22:41:06,737 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystem.java:initRetryCache(1105)) - Retry cache on
namenode is enabled
2020-10-23 22:41:06,738 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystem.java:initRetryCache(1113)) - Retry cache
will use 0.03 of total heap and retry cache entry expiry time is 600000 millis
2020-10-23 22:41:06,738 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
NameNodeRetryCache
2020-10-23 22:41:06,738 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
2020-10-23 22:41:06,738 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(397)) - 0.029999999329447746% max memory
1.9 GB = 595.2 KB
2020-10-23 22:41:06,739 [Listener at localhost/37463] INFO util.GSet
(LightWeightGSet.java:computeCapacity(402)) - capacity = 2^16 = 65536
entries
2020-10-23 22:41:06,778 [Listener at localhost/37463] INFO common.Storage
(Storage.java:tryLock(928)) - Lock on
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/name-0-1/in_use.lock
acquired by nodename 674@b2149aa4f159
2020-10-23 22:41:06,829 [Listener at localhost/37463] INFO common.Storage
(Storage.java:tryLock(928)) - Lock on
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/name-0-2/in_use.lock
acquired by nodename 674@b2149aa4f159
2020-10-23 22:41:06,831 [Listener at localhost/37463] INFO
namenode.FileJournalManager
(FileJournalManager.java:recoverUnfinalizedSegments(428)) - Recovering
unfinalized segments in
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/name-0-1/current
2020-10-23 22:41:06,831 [Listener at localhost/37463] INFO
namenode.FileJournalManager
(FileJournalManager.java:recoverUnfinalizedSegments(428)) - Recovering
unfinalized segments in
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/name-0-2/current
2020-10-23 22:41:06,832 [Listener at localhost/37463] INFO namenode.FSImage
(FSImage.java:loadFSImage(733)) - No edit log streams selected.
2020-10-23 22:41:06,832 [Listener at localhost/37463] INFO namenode.FSImage
(FSImage.java:loadFSImageFile(799)) - Planning to load image:
FSImageFile(file=/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/name-0-1/current/fsimage_0000000000000000000,
cpktTxId=0000000000000000000)
2020-10-23 22:41:06,833 [Listener at localhost/37463] INFO
namenode.FSImageFormatPBINode
(FSImageFormatPBINode.java:loadINodeSectionHeader(413)) - Loading 1 INodes.
2020-10-23 22:41:06,837 [Listener at localhost/37463] INFO
namenode.FSImageFormatPBINode (FSImageFormatPBINode.java:loadINodeSection(371))
- Successfully loaded 1 inodes
2020-10-23 22:41:06,837 [Listener at localhost/37463] INFO
namenode.FSImageFormatPBINode
(FSImageFormatPBINode.java:waitBlocksMapAndNameCacheUpdateFinished(344)) -
Completed update blocks map and name cache, total waiting duration 0ms.
2020-10-23 22:41:06,837 [Listener at localhost/37463] INFO
namenode.FSImageFormatProtobuf (FSImageFormatProtobuf.java:load(253)) - Loaded
FSImage in 0 seconds.
2020-10-23 22:41:06,838 [Listener at localhost/37463] INFO namenode.FSImage
(FSImage.java:loadFSImage(977)) - Loaded image for txid 0 from
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/name-0-1/current/fsimage_0000000000000000000
2020-10-23 22:41:06,838 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystem.java:loadFSImage(1227)) - Need to save fs
image? false (staleImage=false, haEnabled=false, isRollingUpgrade=false)
2020-10-23 22:41:06,840 [Listener at localhost/37463] INFO
namenode.FSEditLog (FSEditLog.java:startLogSegment(1391)) - Starting log
segment at 1
2020-10-23 22:41:06,956 [Listener at localhost/37463] INFO
namenode.NameCache (NameCache.java:initialized(143)) - initialized with 0
entries 0 lookups
2020-10-23 22:41:06,956 [Listener at localhost/37463] INFO
namenode.FSNamesystem (FSNamesystem.java:loadFromDisk(800)) - Finished loading
FSImage in 217 msecs
2020-10-23 22:41:06,957 [Listener at localhost/37463] INFO
namenode.NameNode (NameNodeRpcServer.java:<init>(454)) - RPC server is binding
to localhost:0
2020-10-23 22:41:06,957 [Listener at localhost/37463] INFO
namenode.NameNode (NameNodeRpcServer.java:<init>(459)) - Enable NameNode state
context:false
2020-10-23 22:41:06,957 [Listener at localhost/37463] INFO
ipc.CallQueueManager (CallQueueManager.java:<init>(92)) - Using callQueue:
class java.util.concurrent.LinkedBlockingQueue, queueCapacity: 1000, scheduler:
class org.apache.hadoop.ipc.DefaultRpcScheduler, ipcBackoff: false.
2020-10-23 22:41:06,958 [Socket Reader #1 for port 0] INFO ipc.Server
(Server.java:run(1250)) - Starting Socket Reader #1 for port 0
2020-10-23 22:41:06,961 [Listener at localhost/36353] INFO
namenode.NameNode (NameNode.java:initialize(774)) - Clients are to use
localhost:36353 to access this namenode/service.
2020-10-23 22:41:06,962 [Listener at localhost/36353] INFO
namenode.FSNamesystem (FSNamesystem.java:registerMBean(5508)) - Registered
FSNamesystemState, ReplicatedBlocksState and ECBlockGroupsState MBeans.
2020-10-23 22:41:07,022 [Listener at localhost/36353] INFO
namenode.LeaseManager (LeaseManager.java:getNumUnderConstructionBlocks(178)) -
Number of blocks under construction: 0
2020-10-23 22:41:07,023 [Listener at localhost/36353] INFO
blockmanagement.DatanodeAdminDefaultMonitor
(DatanodeAdminDefaultMonitor.java:processConf(116)) - Initialized the Default
Decommission and Maintenance monitor
2020-10-23 22:41:07,025
[org.apache.hadoop.hdfs.server.blockmanagement.HeartbeatManager$Monitor@1d3c112a]
INFO block.BlockTokenSecretManager
(BlockTokenSecretManager.java:updateKeys(258)) - Updating block keys
2020-10-23 22:41:07,027 [Listener at localhost/36353] INFO
blockmanagement.BlockManager (BlockManager.java:initializeReplQueues(5179)) -
initializing replication queues
2020-10-23 22:41:07,028 [Listener at localhost/36353] INFO hdfs.StateChange
(BlockManagerSafeMode.java:leaveSafeMode(408)) - STATE* Leaving safe mode after
0 secs
2020-10-23 22:41:07,029 [Listener at localhost/36353] INFO hdfs.StateChange
(BlockManagerSafeMode.java:leaveSafeMode(414)) - STATE* Network topology has 0
racks and 0 datanodes
2020-10-23 22:41:07,029 [Listener at localhost/36353] INFO hdfs.StateChange
(BlockManagerSafeMode.java:leaveSafeMode(416)) - STATE* UnderReplicatedBlocks
has 0 blocks
2020-10-23 22:41:07,040 [IPC Server Responder] INFO ipc.Server
(Server.java:run(1492)) - IPC Server Responder: starting
2020-10-23 22:41:07,041 [IPC Server listener on 0] INFO ipc.Server
(Server.java:run(1329)) - IPC Server listener on 0: starting
2020-10-23 22:41:07,080 [Listener at localhost/36353] INFO
namenode.NameNode (NameNode.java:startCommonServices(891)) - NameNode RPC up
at: localhost/127.0.0.1:36353
2020-10-23 22:41:07,081 [Reconstruction Queue Initializer] INFO
blockmanagement.BlockManager
(BlockManager.java:processMisReplicatesAsync(3721)) - Total number of blocks
= 0
2020-10-23 22:41:07,081 [Reconstruction Queue Initializer] INFO
blockmanagement.BlockManager
(BlockManager.java:processMisReplicatesAsync(3722)) - Number of invalid blocks
= 0
2020-10-23 22:41:07,081 [Reconstruction Queue Initializer] INFO
blockmanagement.BlockManager
(BlockManager.java:processMisReplicatesAsync(3723)) - Number of
under-replicated blocks = 0
2020-10-23 22:41:07,081 [Reconstruction Queue Initializer] INFO
blockmanagement.BlockManager
(BlockManager.java:processMisReplicatesAsync(3724)) - Number of
over-replicated blocks = 0
2020-10-23 22:41:07,081 [Reconstruction Queue Initializer] INFO
blockmanagement.BlockManager
(BlockManager.java:processMisReplicatesAsync(3726)) - Number of blocks being
written = 0
2020-10-23 22:41:07,081 [Reconstruction Queue Initializer] INFO
hdfs.StateChange (BlockManager.java:processMisReplicatesAsync(3729)) - STATE*
Replication Queue initialization scan for invalid, over- and under-replicated
blocks completed in 52 msec
2020-10-23 22:41:07,081 [Listener at localhost/36353] INFO
namenode.FSNamesystem (FSNamesystem.java:startActiveServices(1339)) - Starting
services required for active state
2020-10-23 22:41:07,081 [Listener at localhost/36353] INFO
namenode.FSDirectory (FSDirectory.java:updateCountForQuota(849)) - Initializing
quota with 4 thread(s)
2020-10-23 22:41:07,083 [Listener at localhost/36353] INFO
namenode.FSDirectory (FSDirectory.java:updateCountForQuota(858)) - Quota
initialization completed in 1 milliseconds
name space=1
storage space=0
storage types=RAM_DISK=0, NVDIMM=0, SSD=0, DISK=0, ARCHIVE=0, PROVIDED=0
2020-10-23 22:41:07,096 [CacheReplicationMonitor(1368622310)] INFO
blockmanagement.CacheReplicationMonitor (CacheReplicationMonitor.java:run(160))
- Starting CacheReplicationMonitor with interval 30000 milliseconds
2020-10-23 22:41:07,546 [Listener at localhost/36353] INFO
hdfs.MiniDFSCluster (MiniDFSCluster.java:startDataNodes(1701)) - Starting
DataNode 0 with dfs.datanode.data.dir:
[DISK]file:/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/data/data1,[DISK]file:/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/data/data2
2020-10-23 22:41:07,547 [Listener at localhost/36353] INFO
checker.ThrottledAsyncChecker (ThrottledAsyncChecker.java:schedule(137)) -
Scheduling a check for
[DISK]file:/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/data/data1
2020-10-23 22:41:07,548 [Listener at localhost/36353] INFO
checker.ThrottledAsyncChecker (ThrottledAsyncChecker.java:schedule(137)) -
Scheduling a check for
[DISK]file:/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/data/data2
2020-10-23 22:41:07,561 [Listener at localhost/36353] INFO
impl.MetricsSystemImpl (MetricsSystemImpl.java:init(158)) - DataNode metrics
system started (again)
2020-10-23 22:41:07,562 [Listener at localhost/36353] INFO common.Util
(Util.java:isDiskStatsEnabled(395)) -
dfs.datanode.fileio.profiling.sampling.percentage set to 0. Disabling file IO
profiling
2020-10-23 22:41:07,562 [Listener at localhost/36353] INFO
datanode.BlockScanner (BlockScanner.java:<init>(201)) - Initialized block
scanner with targetBytesPerSec 1048576
2020-10-23 22:41:07,562 [Listener at localhost/36353] INFO
datanode.DataNode (DataNode.java:<init>(512)) - Configured hostname is 127.0.0.1
2020-10-23 22:41:07,563 [Listener at localhost/36353] INFO common.Util
(Util.java:isDiskStatsEnabled(395)) -
dfs.datanode.fileio.profiling.sampling.percentage set to 0. Disabling file IO
profiling
2020-10-23 22:41:07,563 [Listener at localhost/36353] INFO
datanode.DataNode (DataNode.java:startDataNode(1422)) - Starting DataNode with
maxLockedMemory = 0
2020-10-23 22:41:07,564 [Listener at localhost/36353] INFO
datanode.DataNode (DataNode.java:initDataXceiver(1170)) - Opened streaming
server at /127.0.0.1:39239
2020-10-23 22:41:07,564 [Listener at localhost/36353] INFO
datanode.DataNode (DataXceiverServer.java:<init>(94)) - Balancing bandwidth is
104857600 bytes/s
2020-10-23 22:41:07,564 [Listener at localhost/36353] INFO
datanode.DataNode (DataXceiverServer.java:<init>(95)) - Number threads for
balancing is 100
2020-10-23 22:41:07,573 [Listener at localhost/36353] INFO http.HttpServer2
(HttpServer2.java:getWebAppsPath(1141)) - Web server is in development mode.
Resources will be read from the source tree.
2020-10-23 22:41:07,575 [Listener at localhost/36353] INFO
server.AuthenticationFilter
(AuthenticationFilter.java:constructSecretProvider(240)) - Unable to initialize
FileSignerSecretProvider, falling back to use random secrets.
2020-10-23 22:41:07,577 [Listener at localhost/36353] INFO
http.HttpRequestLog (HttpRequestLog.java:getRequestLog(82)) - Http request log
for http.requests.datanode is not defined
2020-10-23 22:41:07,577 [Listener at localhost/36353] INFO http.HttpServer2
(HttpServer2.java:getWebAppsPath(1141)) - Web server is in development mode.
Resources will be read from the source tree.
2020-10-23 22:41:07,579 [Listener at localhost/36353] INFO http.HttpServer2
(HttpServer2.java:addGlobalFilter(1059)) - Added global filter 'safety'
(class=org.apache.hadoop.http.HttpServer2$QuotingInputFilter)
2020-10-23 22:41:07,580 [Listener at localhost/36353] INFO http.HttpServer2
(HttpServer2.java:addFilter(1032)) - Added filter static_user_filter
(class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
context datanode
2020-10-23 22:41:07,580 [Listener at localhost/36353] INFO http.HttpServer2
(HttpServer2.java:addFilter(1042)) - Added filter static_user_filter
(class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
context static
2020-10-23 22:41:07,580 [Listener at localhost/36353] INFO http.HttpServer2
(HttpServer2.java:addFilter(1042)) - Added filter static_user_filter
(class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
context logs
2020-10-23 22:41:07,581 [Listener at localhost/36353] INFO http.HttpServer2
(HttpServer2.java:bindListener(1280)) - Jetty bound to port 37573
2020-10-23 22:41:07,581 [Listener at localhost/36353] INFO server.Server
(Server.java:doStart(359)) - jetty-9.4.20.v20190813; built:
2019-08-13T21:28:18.144Z; git: 84700530e645e812b336747464d6fbbf370c9a20; jvm
1.8.0_265-8u265-b01-0ubuntu2~18.04-b01
2020-10-23 22:41:07,595 [Listener at localhost/36353] INFO server.session
(DefaultSessionIdManager.java:doStart(333)) - DefaultSessionIdManager
workerName=node0
2020-10-23 22:41:07,595 [Listener at localhost/36353] INFO server.session
(DefaultSessionIdManager.java:doStart(338)) - No SessionScavenger set, using
defaults
2020-10-23 22:41:07,596 [Listener at localhost/36353] INFO server.session
(HouseKeeper.java:startScavenging(140)) - node0 Scavenging every 660000ms
2020-10-23 22:41:07,596 [Listener at localhost/36353] INFO
handler.ContextHandler (ContextHandler.java:doStart(824)) - Started
o.e.j.s.ServletContextHandler@3380ca3d{logs,/logs,file:///home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/log/,AVAILABLE}
2020-10-23 22:41:07,597 [Listener at localhost/36353] INFO
handler.ContextHandler (ContextHandler.java:doStart(824)) - Started
o.e.j.s.ServletContextHandler@c2df90e{static,/static,file:///home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/src/main/webapps/static/,AVAILABLE}
2020-10-23 22:41:07,602 [Listener at localhost/36353] INFO
handler.ContextHandler (ContextHandler.java:doStart(824)) - Started
o.e.j.w.WebAppContext@385d819{datanode,/,file:///home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/src/main/webapps/datanode/,AVAILABLE}{file:/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/src/main/webapps/datanode}
2020-10-23 22:41:07,603 [Listener at localhost/36353] INFO
server.AbstractConnector (AbstractConnector.java:doStart(293)) - Started
ServerConnector@87d9a01{HTTP/1.1,[http/1.1]}{localhost:37573}
2020-10-23 22:41:07,603 [Listener at localhost/36353] INFO server.Server
(Server.java:doStart(399)) - Started @62042ms
2020-10-23 22:41:07,607 [Listener at localhost/36353] WARN
web.DatanodeHttpServer (RestCsrfPreventionFilterHandler.java:<init>(75)) - Got
null for restCsrfPreventionFilter - will not do any filtering.
2020-10-23 22:41:07,617 [Listener at localhost/36353] INFO
web.DatanodeHttpServer (DatanodeHttpServer.java:start(322)) - Listening HTTP
traffic on /127.0.0.1:43455
2020-10-23 22:41:07,619 [Listener at localhost/36353] INFO
datanode.DataNode (DataNode.java:startDataNode(1450)) - dnUserName = jenkins
2020-10-23 22:41:07,619 [Listener at localhost/36353] INFO
datanode.DataNode (DataNode.java:startDataNode(1451)) - supergroup = supergroup
2020-10-23 22:41:07,620 [Listener at localhost/36353] INFO
ipc.CallQueueManager (CallQueueManager.java:<init>(92)) - Using callQueue:
class java.util.concurrent.LinkedBlockingQueue, queueCapacity: 1000, scheduler:
class org.apache.hadoop.ipc.DefaultRpcScheduler, ipcBackoff: false.
2020-10-23 22:41:07,619
[org.apache.hadoop.util.JvmPauseMonitor$Monitor@6d963d70] INFO
util.JvmPauseMonitor (JvmPauseMonitor.java:run(188)) - Starting JVM pause
monitor
2020-10-23 22:41:07,621 [Socket Reader #1 for port 0] INFO ipc.Server
(Server.java:run(1250)) - Starting Socket Reader #1 for port 0
2020-10-23 22:41:07,623 [Listener at localhost/46345] INFO
datanode.DataNode (DataNode.java:initIpcServer(1057)) - Opened IPC server at
/127.0.0.1:46345
2020-10-23 22:41:07,636 [Listener at localhost/46345] INFO
datanode.DataNode (BlockPoolManager.java:refreshNamenodes(149)) - Refresh
request received for nameservices: null
2020-10-23 22:41:07,637 [Listener at localhost/46345] INFO
datanode.DataNode (BlockPoolManager.java:doRefreshNamenodes(210)) - Starting
BPOfferServices for nameservices: <default>
2020-10-23 22:41:07,642 [Thread-4271] INFO datanode.DataNode
(BPServiceActor.java:run(846)) - Block pool <registering> (Datanode Uuid
unassigned) service to localhost/127.0.0.1:36353 starting to offer service
2020-10-23 22:41:07,645 [IPC Server Responder] INFO ipc.Server
(Server.java:run(1492)) - IPC Server Responder: starting
2020-10-23 22:41:07,649 [IPC Server listener on 0] INFO ipc.Server
(Server.java:run(1329)) - IPC Server listener on 0: starting
2020-10-23 22:41:07,701 [Thread-4271] INFO datanode.DataNode
(BPOfferService.java:verifyAndSetNamespaceInfo(380)) - Acknowledging ACTIVE
Namenode during handshakeBlock pool <registering> (Datanode Uuid unassigned)
service to localhost/127.0.0.1:36353
2020-10-23 22:41:07,701 [Thread-4271] INFO common.Storage
(DataStorage.java:getParallelVolumeLoadThreadsNum(356)) - Using 2 threads to
upgrade data directories (dfs.datanode.parallel.volumes.load.threads.num=2,
dataDirs=2)
2020-10-23 22:41:07,742 [Listener at localhost/46345] INFO
hdfs.MiniDFSCluster (MiniDFSCluster.java:startDataNodes(1701)) - Starting
DataNode 1 with dfs.datanode.data.dir:
[DISK]file:/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/data/data3,[DISK]file:/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/data/data4
2020-10-23 22:41:07,743 [Listener at localhost/46345] INFO
checker.ThrottledAsyncChecker (ThrottledAsyncChecker.java:schedule(137)) -
Scheduling a check for
[DISK]file:/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/data/data3
2020-10-23 22:41:07,744 [Listener at localhost/46345] INFO
checker.ThrottledAsyncChecker (ThrottledAsyncChecker.java:schedule(137)) -
Scheduling a check for
[DISK]file:/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/data/data4
2020-10-23 22:41:07,749 [Thread-4271] INFO common.Storage
(Storage.java:tryLock(928)) - Lock on
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/data/data1/in_use.lock
acquired by nodename 674@b2149aa4f159
2020-10-23 22:41:07,749 [Thread-4271] INFO common.Storage
(DataStorage.java:loadStorageDirectory(284)) - Storage directory with location
[DISK]file:/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/data/data1
is not formatted for namespace 593244777. Formatting...
2020-10-23 22:41:07,749 [Thread-4271] INFO common.Storage
(DataStorage.java:createStorageID(160)) - Generated new storageID
DS-e9764209-9d9c-4f2f-843c-183cb415a2ec for directory
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/data/data1
2020-10-23 22:41:07,749 [Listener at localhost/46345] INFO
impl.MetricsSystemImpl (MetricsSystemImpl.java:init(158)) - DataNode metrics
system started (again)
2020-10-23 22:41:07,750 [Listener at localhost/46345] INFO common.Util
(Util.java:isDiskStatsEnabled(395)) -
dfs.datanode.fileio.profiling.sampling.percentage set to 0. Disabling file IO
profiling
2020-10-23 22:41:07,750 [Listener at localhost/46345] INFO
datanode.BlockScanner (BlockScanner.java:<init>(201)) - Initialized block
scanner with targetBytesPerSec 1048576
2020-10-23 22:41:07,751 [Listener at localhost/46345] INFO
datanode.DataNode (DataNode.java:<init>(512)) - Configured hostname is 127.0.0.1
2020-10-23 22:41:07,751 [Listener at localhost/46345] INFO common.Util
(Util.java:isDiskStatsEnabled(395)) -
dfs.datanode.fileio.profiling.sampling.percentage set to 0. Disabling file IO
profiling
2020-10-23 22:41:07,751 [Listener at localhost/46345] INFO
datanode.DataNode (DataNode.java:startDataNode(1422)) - Starting DataNode with
maxLockedMemory = 0
2020-10-23 22:41:07,752 [Listener at localhost/46345] INFO
datanode.DataNode (DataNode.java:initDataXceiver(1170)) - Opened streaming
server at /127.0.0.1:35165
2020-10-23 22:41:07,752 [Listener at localhost/46345] INFO
datanode.DataNode (DataXceiverServer.java:<init>(94)) - Balancing bandwidth is
104857600 bytes/s
2020-10-23 22:41:07,752 [Listener at localhost/46345] INFO
datanode.DataNode (DataXceiverServer.java:<init>(95)) - Number threads for
balancing is 100
2020-10-23 22:41:07,755 [Listener at localhost/46345] INFO http.HttpServer2
(HttpServer2.java:getWebAppsPath(1141)) - Web server is in development mode.
Resources will be read from the source tree.
2020-10-23 22:41:07,757 [Listener at localhost/46345] INFO
server.AuthenticationFilter
(AuthenticationFilter.java:constructSecretProvider(240)) - Unable to initialize
FileSignerSecretProvider, falling back to use random secrets.
2020-10-23 22:41:07,775 [Listener at localhost/46345] INFO
http.HttpRequestLog (HttpRequestLog.java:getRequestLog(82)) - Http request log
for http.requests.datanode is not defined
2020-10-23 22:41:07,775 [Listener at localhost/46345] INFO http.HttpServer2
(HttpServer2.java:getWebAppsPath(1141)) - Web server is in development mode.
Resources will be read from the source tree.
2020-10-23 22:41:07,778 [Li
...[truncated 774850 chars]...
b415a2ec, because there is no volume scanner for that storageId.
2020-10-23 22:41:18,340 [DataXceiver for client at /127.0.0.1:40640
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] ERROR
datanode.DataNode (BlockSender.java:sendPacket(655)) - BlockSender.sendChunks()
exception:
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479720
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,341 [DataXceiver for client at /127.0.0.1:40640
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] INFO
datanode.BlockScanner (BlockScanner.java:markSuspectBlock(369)) - Not scanning
suspicious block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001 on
DS-e9764209-9d9c-4f2f-843c-183cb415a2ec, because there is no volume scanner for
that storageId.
2020-10-23 22:41:18,340 [DataXceiver for client at /127.0.0.1:40616
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] ERROR
datanode.DataNode (BlockSender.java:sendPacket(655)) - BlockSender.sendChunks()
exception:
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479693
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,341 [DataXceiver for client at /127.0.0.1:40616
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] INFO
datanode.BlockScanner (BlockScanner.java:markSuspectBlock(369)) - Not scanning
suspicious block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001 on
DS-e9764209-9d9c-4f2f-843c-183cb415a2ec, because there is no volume scanner for
that storageId.
2020-10-23 22:41:18,340 [DataXceiver for client at /127.0.0.1:40490
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] ERROR
datanode.DataNode (BlockSender.java:sendPacket(655)) - BlockSender.sendChunks()
exception:
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479440
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,340 [DataXceiver for client at /127.0.0.1:40564
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] ERROR
datanode.DataNode (BlockSender.java:sendPacket(655)) - BlockSender.sendChunks()
exception:
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479528
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,340 [DataXceiver for client at /127.0.0.1:40588
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] ERROR
datanode.DataNode (BlockSender.java:sendPacket(655)) - BlockSender.sendChunks()
exception:
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479561
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,340 [DataXceiver for client at /127.0.0.1:40540
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] ERROR
datanode.DataNode (BlockSender.java:sendPacket(655)) - BlockSender.sendChunks()
exception:
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479500
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,340 [Listener at localhost/45103] INFO ipc.Server
(Server.java:stop(3400)) - Stopping server on 46345
2020-10-23 22:41:18,340 [DataXceiver for client at /127.0.0.1:40464
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] ERROR
datanode.DataNode (BlockSender.java:sendPacket(655)) - BlockSender.sendChunks()
exception:
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479392
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,341 [DataXceiver for client at /127.0.0.1:40490
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] INFO
datanode.BlockScanner (BlockScanner.java:markSuspectBlock(369)) - Not scanning
suspicious block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001 on
DS-e9764209-9d9c-4f2f-843c-183cb415a2ec, because there is no volume scanner for
that storageId.
2020-10-23 22:41:18,343 [DataXceiver for client at /127.0.0.1:40490
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] WARN
datanode.DataNode (DataXceiver.java:readBlock(646)) -
DatanodeRegistration(127.0.0.1:39239,
datanodeUuid=558a8b95-8213-4cf4-913d-744173bf0ab0, infoPort=43455,
infoSecurePort=0, ipcPort=46345,
storageInfo=lv=-57;cid=testClusterID;nsid=593244777;c=1603492866371):Got
exception while serving
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001 to
/127.0.0.1:40490
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479440
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,343 [Command processor] ERROR datanode.DataNode
(BPServiceActor.java:processQueue(1329)) - Command processor encountered
interrupt and exit.
2020-10-23 22:41:18,341 [DataXceiver for client at /127.0.0.1:40616
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] WARN
datanode.DataNode (DataXceiver.java:readBlock(646)) -
DatanodeRegistration(127.0.0.1:39239,
datanodeUuid=558a8b95-8213-4cf4-913d-744173bf0ab0, infoPort=43455,
infoSecurePort=0, ipcPort=46345,
storageInfo=lv=-57;cid=testClusterID;nsid=593244777;c=1603492866371):Got
exception while serving
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001 to
/127.0.0.1:40616
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479693
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,341 [DataXceiver for client at /127.0.0.1:40640
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] WARN
datanode.DataNode (DataXceiver.java:readBlock(646)) -
DatanodeRegistration(127.0.0.1:39239,
datanodeUuid=558a8b95-8213-4cf4-913d-744173bf0ab0, infoPort=43455,
infoSecurePort=0, ipcPort=46345,
storageInfo=lv=-57;cid=testClusterID;nsid=593244777;c=1603492866371):Got
exception while serving
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001 to
/127.0.0.1:40640
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479720
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,341 [DataXceiver for client at /127.0.0.1:40514
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] WARN
datanode.DataNode (DataXceiver.java:readBlock(646)) -
DatanodeRegistration(127.0.0.1:39239,
datanodeUuid=558a8b95-8213-4cf4-913d-744173bf0ab0, infoPort=43455,
infoSecurePort=0, ipcPort=46345,
storageInfo=lv=-57;cid=testClusterID;nsid=593244777;c=1603492866371):Got
exception while serving
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001 to
/127.0.0.1:40514
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479468
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,343 [DataXceiver for client at /127.0.0.1:40514
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] ERROR
datanode.DataNode (DataXceiver.java:run(324)) - 127.0.0.1:39239:DataXceiver
error processing READ_BLOCK operation src: /127.0.0.1:40514 dst:
/127.0.0.1:39239
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479468
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,343 [DataXceiver for client at /127.0.0.1:40640
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] ERROR
datanode.DataNode (DataXceiver.java:run(324)) - 127.0.0.1:39239:DataXceiver
error processing READ_BLOCK operation src: /127.0.0.1:40640 dst:
/127.0.0.1:39239
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479720
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,343 [DataXceiver for client at /127.0.0.1:40616
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] ERROR
datanode.DataNode (DataXceiver.java:run(324)) - 127.0.0.1:39239:DataXceiver
error processing READ_BLOCK operation src: /127.0.0.1:40616 dst:
/127.0.0.1:39239
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479693
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,343 [DataXceiver for client at /127.0.0.1:40490
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] ERROR
datanode.DataNode (DataXceiver.java:run(324)) - 127.0.0.1:39239:DataXceiver
error processing READ_BLOCK operation src: /127.0.0.1:40490 dst:
/127.0.0.1:39239
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479440
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,343 [BP-1233294053-172.17.0.2-1603492866371 heartbeating
to localhost/127.0.0.1:36353] WARN datanode.IncrementalBlockReportManager
(IncrementalBlockReportManager.java:waitTillNextIBR(160)) -
IncrementalBlockReportManager interrupted
2020-10-23 22:41:18,343 [IPC Server Responder] INFO ipc.Server
(Server.java:run(1497)) - Stopping IPC Server Responder
2020-10-23 22:41:18,343 [DataXceiver for client at /127.0.0.1:40464
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] INFO
datanode.BlockScanner (BlockScanner.java:markSuspectBlock(369)) - Not scanning
suspicious block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001 on
DS-e9764209-9d9c-4f2f-843c-183cb415a2ec, because there is no volume scanner for
that storageId.
2020-10-23 22:41:18,342 [IPC Server listener on 0] INFO ipc.Server
(Server.java:run(1361)) - Stopping IPC Server listener on 0
2020-10-23 22:41:18,345 [DataXceiver for client at /127.0.0.1:40464
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] WARN
datanode.DataNode (DataXceiver.java:readBlock(646)) -
DatanodeRegistration(127.0.0.1:39239,
datanodeUuid=558a8b95-8213-4cf4-913d-744173bf0ab0, infoPort=43455,
infoSecurePort=0, ipcPort=46345,
storageInfo=lv=-57;cid=testClusterID;nsid=593244777;c=1603492866371):Got
exception while serving
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001 to
/127.0.0.1:40464
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479392
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,345 [DataXceiver for client at /127.0.0.1:40540
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] INFO
datanode.BlockScanner (BlockScanner.java:markSuspectBlock(369)) - Not scanning
suspicious block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001 on
DS-e9764209-9d9c-4f2f-843c-183cb415a2ec, because there is no volume scanner for
that storageId.
2020-10-23 22:41:18,345 [DataXceiver for client at /127.0.0.1:40588
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] INFO
datanode.BlockScanner (BlockScanner.java:markSuspectBlock(369)) - Not scanning
suspicious block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001 on
DS-e9764209-9d9c-4f2f-843c-183cb415a2ec, because there is no volume scanner for
that storageId.
2020-10-23 22:41:18,344 [BP-1233294053-172.17.0.2-1603492866371 heartbeating
to localhost/127.0.0.1:36353] WARN datanode.DataNode
(BPServiceActor.java:run(889)) - Ending block pool service for: Block pool
BP-1233294053-172.17.0.2-1603492866371 (Datanode Uuid
558a8b95-8213-4cf4-913d-744173bf0ab0) service to localhost/127.0.0.1:36353
2020-10-23 22:41:18,345 [DataXceiver for client at /127.0.0.1:40588
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] WARN
datanode.DataNode (DataXceiver.java:readBlock(646)) -
DatanodeRegistration(127.0.0.1:39239,
datanodeUuid=558a8b95-8213-4cf4-913d-744173bf0ab0, infoPort=43455,
infoSecurePort=0, ipcPort=46345,
storageInfo=lv=-57;cid=testClusterID;nsid=593244777;c=1603492866371):Got
exception while serving
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001 to
/127.0.0.1:40588
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479561
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,345 [DataXceiver for client at /127.0.0.1:40564
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] INFO
datanode.BlockScanner (BlockScanner.java:markSuspectBlock(369)) - Not scanning
suspicious block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001 on
DS-e9764209-9d9c-4f2f-843c-183cb415a2ec, because there is no volume scanner for
that storageId.
2020-10-23 22:41:18,345 [DataXceiver for client at /127.0.0.1:40564
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] WARN
datanode.DataNode (DataXceiver.java:readBlock(646)) -
DatanodeRegistration(127.0.0.1:39239,
datanodeUuid=558a8b95-8213-4cf4-913d-744173bf0ab0, infoPort=43455,
infoSecurePort=0, ipcPort=46345,
storageInfo=lv=-57;cid=testClusterID;nsid=593244777;c=1603492866371):Got
exception while serving
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001 to
/127.0.0.1:40564
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479528
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,346 [DataXceiver for client at /127.0.0.1:40564
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] ERROR
datanode.DataNode (DataXceiver.java:run(324)) - 127.0.0.1:39239:DataXceiver
error processing READ_BLOCK operation src: /127.0.0.1:40564 dst:
/127.0.0.1:39239
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479528
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,345 [DataXceiver for client at /127.0.0.1:40540
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] WARN
datanode.DataNode (DataXceiver.java:readBlock(646)) -
DatanodeRegistration(127.0.0.1:39239,
datanodeUuid=558a8b95-8213-4cf4-913d-744173bf0ab0, infoPort=43455,
infoSecurePort=0, ipcPort=46345,
storageInfo=lv=-57;cid=testClusterID;nsid=593244777;c=1603492866371):Got
exception while serving
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001 to
/127.0.0.1:40540
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479500
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,345 [DataXceiver for client at /127.0.0.1:40464
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] ERROR
datanode.DataNode (DataXceiver.java:run(324)) - 127.0.0.1:39239:DataXceiver
error processing READ_BLOCK operation src: /127.0.0.1:40464 dst:
/127.0.0.1:39239
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479392
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,346 [DataXceiver for client at /127.0.0.1:40540
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] ERROR
datanode.DataNode (DataXceiver.java:run(324)) - 127.0.0.1:39239:DataXceiver
error processing READ_BLOCK operation src: /127.0.0.1:40540 dst:
/127.0.0.1:39239
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479500
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,346 [BP-1233294053-172.17.0.2-1603492866371 heartbeating
to localhost/127.0.0.1:36353] INFO datanode.DataNode
(BlockPoolManager.java:remove(102)) - Removed Block pool
BP-1233294053-172.17.0.2-1603492866371 (Datanode Uuid
558a8b95-8213-4cf4-913d-744173bf0ab0)
2020-10-23 22:41:18,346 [BP-1233294053-172.17.0.2-1603492866371 heartbeating
to localhost/127.0.0.1:36353] INFO impl.FsDatasetImpl
(FsDatasetImpl.java:shutdownBlockPool(2950)) - Removing block pool
BP-1233294053-172.17.0.2-1603492866371
2020-10-23 22:41:18,347
[refreshUsed-/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/data/data1/current/BP-1233294053-172.17.0.2-1603492866371]
WARN fs.CachingGetSpaceUsed (CachingGetSpaceUsed.java:run(211)) - Thread
Interrupted waiting to refresh disk information: sleep interrupted
2020-10-23 22:41:18,345 [DataXceiver for client at /127.0.0.1:40588
[Sending block
BP-1233294053-172.17.0.2-1603492866371:blk_-9223372036854775786_1001]] ERROR
datanode.DataNode (DataXceiver.java:run(324)) - 127.0.0.1:39239:DataXceiver
error processing READ_BLOCK operation src: /127.0.0.1:40588 dst:
/127.0.0.1:39239
java.io.InterruptedIOException: Interrupted while waiting for IO on channel
java.nio.channels.SocketChannel[closed]. Total timeout mills is 480000, 479561
millis timeout left.
at
org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:351)
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:245)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:171)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:219)
at
org.apache.hadoop.hdfs.server.datanode.FileIoProvider.transferToSocketFully(FileIoProvider.java:278)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendPacket(BlockSender.java:614)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.doSendBlock(BlockSender.java:809)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:756)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:610)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.opReadBlock(Receiver.java:152)
at
org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.processOp(Receiver.java:104)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:292)
at java.lang.Thread.run(Thread.java:748)
2020-10-23 22:41:18,348
[refreshUsed-/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/data/data2/current/BP-1233294053-172.17.0.2-1603492866371]
WARN fs.CachingGetSpaceUsed (CachingGetSpaceUsed.java:run(211)) - Thread
Interrupted waiting to refresh disk information: sleep interrupted
2020-10-23 22:41:18,348 [Listener at localhost/45103] INFO
impl.FsDatasetAsyncDiskService (FsDatasetAsyncDiskService.java:shutdown(193)) -
Shutting down all async disk service threads
2020-10-23 22:41:18,348 [Listener at localhost/45103] INFO
impl.FsDatasetAsyncDiskService (FsDatasetAsyncDiskService.java:shutdown(201)) -
All async disk service threads have been shut down
2020-10-23 22:41:18,348 [Listener at localhost/45103] INFO
impl.RamDiskAsyncLazyPersistService
(RamDiskAsyncLazyPersistService.java:shutdown(177)) - Shutting down all async
lazy persist service threads
2020-10-23 22:41:18,348 [Listener at localhost/45103] INFO
impl.RamDiskAsyncLazyPersistService
(RamDiskAsyncLazyPersistService.java:shutdown(184)) - All async lazy persist
service threads have been shut down
2020-10-23 22:41:18,348 [Listener at localhost/45103] INFO
impl.MetricsSystemImpl (MetricsSystemImpl.java:stop(210)) - Stopping DataNode
metrics system...
2020-10-23 22:41:18,349 [Listener at localhost/45103] INFO
impl.MetricsSystemImpl (MetricsSystemImpl.java:stop(216)) - DataNode metrics
system stopped.
2020-10-23 22:41:18,349 [Listener at localhost/45103] INFO
impl.MetricsSystemImpl (MetricsSystemImpl.java:shutdown(611)) - DataNode
metrics system shutdown complete.
2020-10-23 22:41:18,350 [Listener at localhost/45103] INFO
datanode.DataNode (DataNode.java:shutdown(2193)) - Shutdown complete.
2020-10-23 22:41:18,350 [Listener at localhost/45103] INFO
hdfs.MiniDFSCluster (MiniDFSCluster.java:stopAndJoinNameNode(2172)) - Shutting
down the namenode
2020-10-23 22:41:18,350 [Listener at localhost/45103] INFO
namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(1456)) - Stopping
services started for active state
2020-10-23 22:41:18,350 [Listener at localhost/45103] INFO
namenode.FSEditLog (FSEditLog.java:endCurrentLogSegment(1441)) - Ending log
segment 1, 36
2020-10-23 22:41:18,351
[org.apache.hadoop.hdfs.server.namenode.FSNamesystem$LazyPersistFileScrubber@f613067]
INFO namenode.FSNamesystem (FSNamesystem.java:run(4609)) -
LazyPersistFileScrubber was interrupted, exiting
2020-10-23 22:41:18,351
[org.apache.hadoop.hdfs.server.namenode.FSNamesystem$NameNodeEditLogRoller@1578b8ec]
INFO namenode.FSNamesystem (FSNamesystem.java:run(4513)) -
NameNodeEditLogRoller was interrupted, exiting
2020-10-23 22:41:18,352 [Listener at localhost/45103] INFO
namenode.FSEditLog (FSEditLog.java:printStatistics(778)) - Number of
transactions: 37 Total time for transactions(ms): 13 Number of transactions
batched in Syncs: 12 Number of syncs: 26 SyncTimes(ms): 3 1
2020-10-23 22:41:18,352 [Listener at localhost/45103] INFO
namenode.FileJournalManager (FileJournalManager.java:finalizeLogSegment(145)) -
Finalizing edits file
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/name-0-1/current/edits_inprogress_0000000000000000001
->
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/name-0-1/current/edits_0000000000000000001-0000000000000000037
2020-10-23 22:41:18,353 [Listener at localhost/45103] INFO
namenode.FileJournalManager (FileJournalManager.java:finalizeLogSegment(145)) -
Finalizing edits file
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/name-0-2/current/edits_inprogress_0000000000000000001
->
/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/test/data/4/dfs/name-0-2/current/edits_0000000000000000001-0000000000000000037
2020-10-23 22:41:18,353 [FSEditLogAsync] INFO namenode.FSEditLog
(FSEditLogAsync.java:run(253)) - FSEditLogAsync was interrupted, exiting
2020-10-23 22:41:18,353 [CacheReplicationMonitor(1368622310)] INFO
blockmanagement.CacheReplicationMonitor (CacheReplicationMonitor.java:run(169))
- Shutting down CacheReplicationMonitor
2020-10-23 22:41:18,353 [Listener at localhost/45103] INFO ipc.Server
(Server.java:stop(3400)) - Stopping server on 36353
2020-10-23 22:41:18,354 [IPC Server listener on 0] INFO ipc.Server
(Server.java:run(1361)) - Stopping IPC Server listener on 0
2020-10-23 22:41:18,354 [RedundancyMonitor] INFO
blockmanagement.BlockManager (BlockManager.java:run(4944)) - Stopping
RedundancyMonitor.
2020-10-23 22:41:18,360 [StorageInfoMonitor] INFO
blockmanagement.BlockManager (BlockManager.java:run(4979)) - Stopping thread.
2020-10-23 22:41:18,359 [IPC Server Responder] INFO ipc.Server
(Server.java:run(1497)) - Stopping IPC Server Responder
2020-10-23 22:41:18,367 [Listener at localhost/45103] INFO
namenode.FSNamesystem (FSNamesystem.java:stopActiveServices(1456)) - Stopping
services started for active state
2020-10-23 22:41:18,367 [Listener at localhost/45103] INFO
namenode.FSNamesystem (FSNamesystem.java:stopStandbyServices(1557)) - Stopping
services started for standby state
2020-10-23 22:41:18,368 [Listener at localhost/45103] INFO
handler.ContextHandler (ContextHandler.java:doStop(1007)) - Stopped
o.e.j.w.WebAppContext@236fdf{hdfs,/,null,UNAVAILABLE}{file:/home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/src/main/webapps/hdfs}
2020-10-23 22:41:18,370 [Listener at localhost/45103] INFO
server.AbstractConnector (AbstractConnector.java:doStop(343)) - Stopped
ServerConnector@49c099b{HTTP/1.1,[http/1.1]}{localhost:0}
2020-10-23 22:41:18,370 [Listener at localhost/45103] INFO server.session
(HouseKeeper.java:stopScavenging(158)) - node0 Stopped scavenging
2020-10-23 22:41:18,370 [Listener at localhost/45103] INFO
handler.ContextHandler (ContextHandler.java:doStop(1007)) - Stopped
o.e.j.s.ServletContextHandler@f2d890c{static,/static,file:///home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/src/main/webapps/static/,UNAVAILABLE}
2020-10-23 22:41:18,371 [Listener at localhost/45103] INFO
handler.ContextHandler (ContextHandler.java:doStop(1007)) - Stopped
o.e.j.s.ServletContextHandler@61149fa5{logs,/logs,file:///home/jenkins/jenkins-home/workspace/hadoop-multibranch_PR-2408/src/hadoop-hdfs-project/hadoop-hdfs/target/log/,UNAVAILABLE}
```
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
us...@infra.apache.org
Issue Time Tracking
-------------------
Worklog Id: (was: 505243)
Time Spent: 1h (was: 50m)
> TestFileChecksumCompositeCrc fails on trunk
> -------------------------------------------
>
> Key: HDFS-15643
> URL: https://issues.apache.org/jira/browse/HDFS-15643
> Project: Hadoop HDFS
> Issue Type: Sub-task
> Reporter: Ahmed Hussein
> Assignee: Ahmed Hussein
> Priority: Critical
> Labels: pull-request-available
> Attachments:
> TestFileChecksum.testStripedFileChecksumWithMissedDataBlocksRangeQuery17.log
>
> Time Spent: 1h
> Remaining Estimate: 0h
>
> There are many failures in {{TestFileChecksumCompositeCrc}}. The test cases
> {{testStripedFileChecksumWithMissedDataBlocksRangeQueryXX}} fail. The
> following is a sample of the stack trace in two of them Query7 and Query8.
> {code:bash}
> org.apache.hadoop.fs.PathIOException: `/striped/stripedFileChecksum1': Fail
> to get block checksum for
> LocatedStripedBlock{BP-1812707539-172.17.0.3-1602771351154:blk_-9223372036854775792_1001;
> getBlockSize()=37748736; corrupt=false; offset=0;
> locs=[DatanodeInfoWithStorage[127.0.0.1:36687,DS-b00139f0-4f28-4870-8f72-b726bd339e23,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:36303,DS-49a3c58e-da4a-4256-b1f9-893e4003ec94,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:43975,DS-ac278858-b6c8-424f-9e20-58d718dabe31,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:37507,DS-17f9d8d8-f8d3-443b-8df7-29416a2f5cb0,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:36441,DS-7e9d19b5-6220-465f-b33e-f8ed0e60fb07,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:42555,DS-ce679f5e-19fe-45b0-a0cd-8d8bec2f4735,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:39093,DS-4a7f54bb-dd39-4b5b-8dee-31a1b565cd7f,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:41699,DS-e1f939f3-37e7-413e-a522-934243477d81,DISK]];
> indices=[1, 2, 3, 4, 5, 6, 7, 8]}
> at
> org.apache.hadoop.hdfs.FileChecksumHelper$StripedFileNonStripedChecksumComputer.checksumBlocks(FileChecksumHelper.java:640)
> at
> org.apache.hadoop.hdfs.FileChecksumHelper$FileChecksumComputer.compute(FileChecksumHelper.java:252)
> at
> org.apache.hadoop.hdfs.DFSClient.getFileChecksumInternal(DFSClient.java:1851)
> at
> org.apache.hadoop.hdfs.DFSClient.getFileChecksumWithCombineMode(DFSClient.java:1871)
> at
> org.apache.hadoop.hdfs.DistributedFileSystem$34.doCall(DistributedFileSystem.java:1902)
> at
> org.apache.hadoop.hdfs.DistributedFileSystem$34.doCall(DistributedFileSystem.java:1899)
> at
> org.apache.hadoop.fs.FileSystemLinkResolver.resolve(FileSystemLinkResolver.java:81)
> at
> org.apache.hadoop.hdfs.DistributedFileSystem.getFileChecksum(DistributedFileSystem.java:1916)
> at
> org.apache.hadoop.hdfs.TestFileChecksum.getFileChecksum(TestFileChecksum.java:584)
> at
> org.apache.hadoop.hdfs.TestFileChecksum.testStripedFileChecksumWithMissedDataBlocksRangeQuery(TestFileChecksum.java:295)
> at
> org.apache.hadoop.hdfs.TestFileChecksum.testStripedFileChecksumWithMissedDataBlocksRangeQuery7(TestFileChecksum.java:377)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
> at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
> at
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
> at
> org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:298)
> at
> org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:292)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at java.lang.Thread.run(Thread.java:748)
> {code}
>
> {code:bash}
> Error Message
> `/striped/stripedFileChecksum1': Fail to get block checksum for
> LocatedStripedBlock{BP-1299291876-172.17.0.3-1602771356932:blk_-9223372036854775792_1001;
> getBlockSize()=37748736; corrupt=false; offset=0;
> locs=[DatanodeInfoWithStorage[127.0.0.1:42217,DS-6c29e4b7-e4f1-4302-ad23-fb078f37d783,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:41307,DS-3d824f14-3cd0-46b1-bef1-caa808bf278d,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:37193,DS-eeb44ff5-fdf1-4774-b6cf-5be7c40147a9,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:39897,DS-36d2fbfc-64bc-405c-8360-735f1ad92e30,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:35545,DS-6fd42817-efea-416e-92fb-3e9034705142,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:39945,DS-501deff8-b6df-4cf0-9ac1-154a4253eec8,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:41359,DS-9b0449f5-377b-4a76-9eb6-0bcf2984b4bb,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:36123,DS-4184ab4a-079d-4b1c-a8cb-2ba22b0baafb,DISK]];
> indices=[0, 1, 2, 3, 4, 6, 7, 8]}
> Stacktrace
> org.apache.hadoop.fs.PathIOException: `/striped/stripedFileChecksum1': Fail
> to get block checksum for
> LocatedStripedBlock{BP-1299291876-172.17.0.3-1602771356932:blk_-9223372036854775792_1001;
> getBlockSize()=37748736; corrupt=false; offset=0;
> locs=[DatanodeInfoWithStorage[127.0.0.1:42217,DS-6c29e4b7-e4f1-4302-ad23-fb078f37d783,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:41307,DS-3d824f14-3cd0-46b1-bef1-caa808bf278d,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:37193,DS-eeb44ff5-fdf1-4774-b6cf-5be7c40147a9,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:39897,DS-36d2fbfc-64bc-405c-8360-735f1ad92e30,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:35545,DS-6fd42817-efea-416e-92fb-3e9034705142,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:39945,DS-501deff8-b6df-4cf0-9ac1-154a4253eec8,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:41359,DS-9b0449f5-377b-4a76-9eb6-0bcf2984b4bb,DISK],
>
> DatanodeInfoWithStorage[127.0.0.1:36123,DS-4184ab4a-079d-4b1c-a8cb-2ba22b0baafb,DISK]];
> indices=[0, 1, 2, 3, 4, 6, 7, 8]}
> at
> org.apache.hadoop.hdfs.FileChecksumHelper$StripedFileNonStripedChecksumComputer.checksumBlocks(FileChecksumHelper.java:640)
> at
> org.apache.hadoop.hdfs.FileChecksumHelper$FileChecksumComputer.compute(FileChecksumHelper.java:252)
> at
> org.apache.hadoop.hdfs.DFSClient.getFileChecksumInternal(DFSClient.java:1851)
> at
> org.apache.hadoop.hdfs.DFSClient.getFileChecksumWithCombineMode(DFSClient.java:1871)
> at
> org.apache.hadoop.hdfs.DistributedFileSystem$34.doCall(DistributedFileSystem.java:1902)
> at
> org.apache.hadoop.hdfs.DistributedFileSystem$34.doCall(DistributedFileSystem.java:1899)
> at
> org.apache.hadoop.fs.FileSystemLinkResolver.resolve(FileSystemLinkResolver.java:81)
> at
> org.apache.hadoop.hdfs.DistributedFileSystem.getFileChecksum(DistributedFileSystem.java:1916)
> at
> org.apache.hadoop.hdfs.TestFileChecksum.getFileChecksum(TestFileChecksum.java:584)
> at
> org.apache.hadoop.hdfs.TestFileChecksum.testStripedFileChecksumWithMissedDataBlocksRangeQuery(TestFileChecksum.java:295)
> at
> org.apache.hadoop.hdfs.TestFileChecksum.testStripedFileChecksumWithMissedDataBlocksRangeQuery8(TestFileChecksum.java:388)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
> at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
> at
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
> at
> org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:298)
> at
> org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:292)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at java.lang.Thread.run(Thread.java:748)
> {code}
>
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: hdfs-issues-unsubscr...@hadoop.apache.org
For additional commands, e-mail: hdfs-issues-h...@hadoop.apache.org
