I'm trying to test some services that require HDFS using Docker Compose. Since the services being tested, namenode, and data node(s) will all be running on the same physical machine (dev laptop), it would be nice to reduce the memory usage by only running one data node. I'm using these docker images.
If I run a name node and 3 data nodes, all works as expected. I tried to run only one data node by setting this in the hdfs-site.xml
of both nodes, and running only 1 data node via compose:
<property><name>dfs.replication</name><value>1</value></property>
It's definitely picking this up, because when it starts I see this in the log:
blockmanagement.BlockManager: defaultReplication = 1
blockmanagement.BlockManager: maxReplication = 512
blockmanagement.BlockManager: minReplication = 1
blockmanagement.BlockManager: maxReplicationStreams = 2
blockmanagement.BlockManager: replicationRecheckInterval = 3000
The first write succeeds just fine. For the second write, I get this (on the client app; no logs about it on the hadoop side):
java.io.IOException: Failed to replace a bad datanode on the existing pipeline due to no more good datanodes being available to try. (Nodes: current=[DatanodeInfoWithStorage[172.18.0.2:50010,DS-f97943bf-2cad-45e5-ae40-9ba947e54404,DISK]], original=[DatanodeInfoWithStorage[172.18.0.2:50010,DS-f97943bf-2cad-45e5-ae40-9ba947e54404,DISK]]). The current failed datanode replacement policy is DEFAULT, and a client may configure this via 'dfs.client.block.write.replace-datanode-on-failure.policy' in its configuration.
at org.apache.hadoop.hdfs.DFSOutputStream$DataStreamer.findNewDatanode(DFSOutputStream.java:929)
at org.apache.hadoop.hdfs.DFSOutputStream$DataStreamer.addDatanode2ExistingPipeline(DFSOutputStream.java:992)
at org.apache.hadoop.hdfs.DFSOutputStream$DataStreamer.setupPipelineForAppendOrRecovery(DFSOutputStream.java:1160)
at org.apache.hadoop.hdfs.DFSOutputStream$DataStreamer.run(DFSOutputStream.java:455)
Each write after that gives this error on both client and HDFS:
Failed to APPEND_FILE (whatever) for (client X) on 172.18.0.6 because this file lease is currently owned by (client Y) on 172.18.0.6
This problem magically goes away if running 3 data nodes. Does anyone have any experience running one name node and one data node in docker? My poor little laptop can't handle the power level of 3 data nodes.
EDIT: I tried this solution here. No dice. Now I get:
17:59:56 WARN hdfs.DFSClient: DataStreamer Exception
org.apache.hadoop.ipc.RemoteException(java.lang.UnsupportedOperationException): This feature is disabled. Please refer to dfs.client.block.write.replace-datanode-on-failure.enable configuration property.
at org.apache.hadoop.hdfs.protocol.datatransfer.ReplaceDatanodeOnFailure.checkEnabled(ReplaceDatanodeOnFailure.java:116)
at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getAdditionalDatanode(FSNamesystem.java:3317)
at org.apache.hadoop.hdfs.server.namenode.NameNodeRpcServer.getAdditionalDatanode(NameNodeRpcServer.java:758)
[...]
Fuller log of the HDFS side (name
is namenode and data
is datanode; the interleaving of logs is not completely chronological because of docker-compose):
name | 16/10/03 18:03:43 INFO hdfs.StateChange: BLOCK* registerDatanode: from DatanodeRegistration(172.18.0.11:50010, datanodeUuid=8ad27f17-7a87-45cb-b782-981c2e7b6dc2, infoPort=50075, infoSecurePort=0, ipcPort=50020, storageInfo=lv=-56;cid=CID-22dd8c41-af12-41ad-81ef-832ebb10ec39;nsid=1117453574;c=0) storage 8ad27f17-7a87-45cb-b782-981c2e7b6dc2
name | 16/10/03 18:03:43 INFO blockmanagement.DatanodeDescriptor: Number of failed storage changes from 0 to 0
data | 16/10/03 18:03:43 INFO datanode.VolumeScanner: VolumeScanner(/hadoop/dfs/data, DS-593eb971-f0cc-4381-a2c7-0befbc4aa9e6): finished scanning block pool BP-1023406345-172.18.0.9-1475517812059
data | 16/10/03 18:03:43 INFO datanode.DataNode: Block pool Block pool BP-1023406345-172.18.0.9-1475517812059 (Datanode Uuid null) service to hadoop-nn1/172.18.0.9:8020 successfully registered with NN
data | 16/10/03 18:03:43 INFO datanode.DataNode: For namenode hadoop-nn1/172.18.0.9:8020 using DELETEREPORT_INTERVAL of 300000 msec BLOCKREPORT_INTERVAL of 21600000msec CACHEREPORT_INTERVAL of 10000msec Initial delay: 0msec; heartBeatInterval=3000
name | 16/10/03 18:03:43 INFO net.NetworkTopology: Adding a new node: /default-rack/172.18.0.11:50010
name | 16/10/03 18:03:44 INFO blockmanagement.DatanodeDescriptor: Number of failed storage changes from 0 to 0
data | 16/10/03 18:03:44 INFO datanode.VolumeScanner: VolumeScanner(/hadoop/dfs/data, DS-593eb971-f0cc-4381-a2c7-0befbc4aa9e6): no suitable block pools found to scan. Waiting 1814399359 ms.
data | 16/10/03 18:03:44 INFO datanode.DataNode: Namenode Block pool BP-1023406345-172.18.0.9-1475517812059 (Datanode Uuid 8ad27f17-7a87-45cb-b782-981c2e7b6dc2) service to hadoop-nn1/172.18.0.9:8020 trying to claim ACTIVE state with txid=1
name | 16/10/03 18:03:44 INFO blockmanagement.DatanodeDescriptor: Adding new storage ID DS-593eb971-f0cc-4381-a2c7-0befbc4aa9e6 for DN 172.18.0.11:50010
data | 16/10/03 18:03:44 INFO datanode.DataNode: Acknowledging ACTIVE Namenode Block pool BP-1023406345-172.18.0.9-1475517812059 (Datanode Uuid 8ad27f17-7a87-45cb-b782-981c2e7b6dc2) service to hadoop-nn1/172.18.0.9:8020
data | 16/10/03 18:03:44 INFO datanode.DataNode: Successfully sent block report 0x8b0c17676f1, containing 1 storage report(s), of which we sent 1. The reports had 0 total blocks and used 1 RPC(s). This took 16 msec to generate and 190 msecs for RPC and NN processing. Got back one command: FinalizeCommand/5.
name | 16/10/03 18:03:44 INFO BlockStateChange: BLOCK* processReport: from storage DS-593eb971-f0cc-4381-a2c7-0befbc4aa9e6 node DatanodeRegistration(172.18.0.11:50010, datanodeUuid=8ad27f17-7a87-45cb-b782-981c2e7b6dc2, infoPort=50075, infoSecurePort=0, ipcPort=50020, storageInfo=lv=-56;cid=CID-22dd8c41-af12-41ad-81ef-832ebb10ec39;nsid=1117453574;c=0), blocks: 0, hasStaleStorage: false, processing time: 2 msecs
name | 16/10/03 18:04:33 INFO hdfs.StateChange: DIR* completeFile: /XXX/appender/1475517840000/.write/172.18.0.6 is closed by DFSClient_NONMAPREDUCE_1250587730_30
data | 16/10/03 18:03:44 INFO datanode.DataNode: Got finalize command for block pool BP-1023406345-172.18.0.9-1475517812059
data | 16/10/03 18:04:34 INFO datanode.DataNode: Receiving BP-1023406345-172.18.0.9-1475517812059:blk_1073741825_1001 src: /172.18.0.6:39732 dest: /172.18.0.11:50010
data | 16/10/03 18:04:34 INFO DataNode.clienttrace: src: /172.18.0.6:39732, dest: /172.18.0.11:50010, bytes: 7421, op: HDFS_WRITE, cliID: DFSClient_NONMAPREDUCE_1250587730_30, offset: 0, srvID: 8ad27f17-7a87-45cb-b782-981c2e7b6dc2, blockid: BP-1023406345-172.18.0.9-1475517812059:blk_1073741825_1001, duration: 107663969
name | 16/10/03 18:04:33 INFO hdfs.StateChange: BLOCK* allocate blk_1073741825_1001{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-593eb971-f0cc-4381-a2c7-0befbc4aa9e6:NORMAL:172.18.0.11:50010|RBW]]} for /XXX/appender/1475517840000/172.18.0.6
name | 16/10/03 18:04:34 INFO namenode.FSNamesystem: BLOCK* blk_1073741825_1001{UCState=COMMITTED, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-593eb971-f0cc-4381-a2c7-0befbc4aa9e6:NORMAL:172.18.0.11:50010|RBW]]} is not COMPLETE (ucState = COMMITTED, replication# = 0 < minimum = 1) in file /XXX/appender/1475517840000/172.18.0.6
name | 16/10/03 18:04:34 INFO BlockStateChange: BLOCK* addStoredBlock: blockMap updated: 172.18.0.11:50010 is added to blk_1073741825_1001{UCState=COMMITTED, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-593eb971-f0cc-4381-a2c7-0befbc4aa9e6:NORMAL:172.18.0.11:50010|RBW]]} size 7421
name | 16/10/03 18:04:34 INFO hdfs.StateChange: DIR* completeFile: /XXX/appender/1475517840000/172.18.0.6 is closed by DFSClient_NONMAPREDUCE_1250587730_30
name | 16/10/03 18:04:45 INFO namenode.FSEditLog: Number of transactions: 14 Total time for transactions(ms): 21 Number of transactions batched in Syncs: 1 Number of syncs: 8 SyncTimes(ms): 17
name | 16/10/03 18:04:45 INFO hdfs.StateChange: DIR* completeFile: /XXX/appender/1475517840000/.write/172.18.0.6 is closed by DFSClient_NONMAPREDUCE_-1821674544_30
name | 16/10/03 18:04:48 WARN hdfs.StateChange: DIR* NameSystem.append: Failed to APPEND_FILE /XXX/appender/1475517840000/172.18.0.6 for DFSClient_NONMAPREDUCE_1129971636_30 on 172.18.0.6 because this file lease is currently owned by DFSClient_NONMAPREDUCE_-1821674544_30 on 172.18.0.6
hdfs.site.xml
(name node):
<configuration>
<property><name>dfs.namenode.name.dir</name><value>file:///hadoop/dfs/name</value></property>
<property><name>dfs.replication</name><value>1</value></property>
<property><name>dfs.namenode.rpc-bind-host</name><value>0.0.0.0</value></property>
<property><name>dfs.namenode.servicerpc-bind-host</name><value>0.0.0.0</value></property>
<property><name>dfs.namenode.http-bind-host</name><value>0.0.0.0</value></property>
<property><name>dfs.namenode.https-bind-host</name><value>0.0.0.0</value></property>
<property><name>dfs.client.use.datanode.hostname</name><value>true</value></property>
<property><name>dfs.datanode.use.datanode.hostname</name><value>true</value></property>
</configuration>
hdfs-site.xml
(data node):
<configuration>
<property><name>dfs.datanode.data.dir</name><value>file:///hadoop/dfs/data</value></property>
<property><name>dfs.replication</name><value>1</value></property>
<property><name>dfs.namenode.rpc-bind-host</name><value>0.0.0.0</value></property>
<property><name>dfs.namenode.servicerpc-bind-host</name><value>0.0.0.0</value></property>
<property><name>dfs.namenode.http-bind-host</name><value>0.0.0.0</value></property>
<property><name>dfs.namenode.https-bind-host</name><value>0.0.0.0</value></property>
<property><name>dfs.client.use.datanode.hostname</name><value>true</value></property>
<property><name>dfs.datanode.use.datanode.hostname</name><value>true</value></property>
</configuration>