Memory leak while submitting Spark apps using Ozone

[aekom87]

Hi, we have been observing the following situation in our Ozone 1.4.1-RC1 cluster.
Our service shows symptoms of quite severe memory leakage while submitting Spark jobs.
Memory profiler points to the org.apache.hadoop.util.CacheMetrics objects from the ozone-filesystetm-hadoop3-1.4.1.jar library. Number of those objects grows over time and that does not seem to stop, ever.

We are not quite sure whether it's a bug of ozone-filesystetm-hadoop3-1.4.1.jar or it's a case of incorrect usage.
One thing to note: when we were using Ozone 1.3.0 (and corresponding client jar ozone-filesystetm-hadoop3-1.3.0.jar) there was no such problem. And we haven't changed anything with regards to submitting Spark jobs (using exactly the same Spark clients libs etc).
Any hints/suggestions would be very appreciated, thanks

[ivandika3]

May I know where does the memory issue happen? Client-side (S3G / Ozone client) or server-side (OM, SCM, DNs)?

Might be related, but 1.4.1 has a memory issue due to regression Ratis version 3.1.0 that causes memory issue. If possible, you can try to downgrade to 1.4.0 first and see if the memory issue improves. We probably will have another RC that upgrades the Ratis version to 3.1.1 that revert the problematic patches.

cc: @xichen01

[aekom87]

On the client side. I've seen this ticket https://issues.apache.org/jira/browse/HDDS-11505 which may be related to my problem (or not). Regarding 1.4.0, thanks, I will check

[ivandika3]

I see, for the Ratis related issue, seems to cause datanodes to OOM so maybe not directly related. Still it's good to either upgrade the Ratis version to 3.1.1 (by backporting https://issues.apache.org/jira/browse/HDDS-11504 directly) or downgrade to 1.4.0 (if backporting is not an option).

@sadanand48 Could you help take a look? There maybe some clients are not closed in ofs?

[adoroszlai]

CacheMetrics usage in XceiverClientManager is new in 1.4.0 (HDDS-8923).

Cleanup happens on close():

ozone/hadoop-hdds/client/src/main/java/org/apache/hadoop/hdds/scm/XceiverClientManager.java

Line 321 in e9fccf4

cacheMetrics.unregister();

XceiverClientManager is closed by RpcClient, which is closed by BasicRootedOzoneClientAdapterImpl.

Are number of XceiverClientManager and RpcClient instances also growing?

[aekom87]

Hi, sorry for the long answer, it took some time to me to investigate calling sequences... At the moment I suspect that the leak can be related to the usage of Hadoop FileContext API

• FileContext API is used by the spark-yarn library which we use to submit Spark applications to our cluster
• FileContext API internally uses AbstractFileSystem API which is implemented by org.apache.hadoop.fs.ozone.RootedOzFs when using ofs filesystem
• org.apache.hadoop.fs.ozone.RootedOzFs internally creates new RootedOzoneFileSystem()
• as it looks to me now, this RootedOzoneFileSystem is never closed and it may cause the leak

Exact stacktrace to display:
at org.apache.hadoop.util.CacheMetrics.create(CacheMetrics.java:80) at org.apache.hadoop.util.CacheMetrics.create(CacheMetrics.java:76) at org.apache.hadoop.hdds.scm.XceiverClientManager.<init>(XceiverClientManager.java:122) at org.apache.hadoop.ozone.client.rpc.RpcClient.createXceiverClientFactory(RpcClient.java:389) at org.apache.hadoop.ozone.client.rpc.RpcClient.<init>(RpcClient.java:290) at org.apache.hadoop.ozone.client.OzoneClientFactory.getClientProtocol(OzoneClientFactory.java:248) at org.apache.hadoop.ozone.client.OzoneClientFactory.getRpcClient(OzoneClientFactory.java:115) at org.apache.hadoop.fs.ozone.BasicRootedOzoneClientAdapterImpl.<init>(BasicRootedOzoneClientAdapterImpl.java:187) at org.apache.hadoop.fs.ozone.RootedOzoneClientAdapterImpl.<init>(RootedOzoneClientAdapterImpl.java:51) at org.apache.hadoop.fs.ozone.RootedOzoneFileSystem.createAdapter(RootedOzoneFileSystem.java:97) at org.apache.hadoop.fs.ozone.BasicRootedOzoneFileSystem.initialize(BasicRootedOzoneFileSystem.java:189) at org.apache.hadoop.fs.DelegateToFileSystem.<init>(DelegateToFileSystem.java:54) at org.apache.hadoop.fs.ozone.RootedOzFs.<init>(RootedOzFs.java:41) at sun.reflect.GeneratedConstructorAccessor34.newInstance(Unknown Source:-1) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:423) at org.apache.hadoop.fs.AbstractFileSystem.newInstance(AbstractFileSystem.java:143) at org.apache.hadoop.fs.AbstractFileSystem.createFileSystem(AbstractFileSystem.java:181) at org.apache.hadoop.fs.AbstractFileSystem.get(AbstractFileSystem.java:266) at org.apache.hadoop.fs.FileContext$2.run(FileContext.java:342) at org.apache.hadoop.fs.FileContext$2.run(FileContext.java:339) at java.security.AccessController.doPrivileged(AccessController.java:-1) at javax.security.auth.Subject.doAs(Subject.java:422) at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1878) at org.apache.hadoop.fs.FileContext.getAbstractFileSystem(FileContext.java:339) at org.apache.hadoop.fs.FileContext.getFileContext(FileContext.java:465) at org.apache.spark.deploy.yarn.Client.$anonfun$copyFileToRemote$5(Client.scala:476) at org.apache.spark.deploy.yarn.Client$$Lambda$393.1989479727.apply(Unknown Source:-1) at scala.collection.mutable.HashMap.getOrElseUpdate(HashMap.scala:86) at org.apache.spark.deploy.yarn.Client.copyFileToRemote(Client.scala:475) at org.apache.spark.deploy.yarn.Client.prepareLocalResources(Client.scala:774) at org.apache.spark.deploy.yarn.Client.createContainerLaunchContext(Client.scala:982) at org.apache.spark.deploy.yarn.Client.submitApplication(Client.scala:220)

[aekom87]

Would be really grateful if you could take a look into my analysis and give you thoughts on which part is to blame here.

[sadanand48]

Looks correct to me, It seems to me like this needs to be fixed in Hadoop, Each time getFSofPath is called and if OFS is not set as defaultFS in each of the API calls a new FS instance is created in turn creating a new OzoneClient that is never closed.

If you have control over how the Filecontext API is called we can use this constructor to already pass an initialized FS instance, use it and at the end close the FS.

public static FileContext getFileContext(AbstractFileSystem defFS,  ConfigurationaConf)

[adoroszlai]

Thanks @aekom87 for the details, very helpful.

• org.apache.hadoop.fs.ozone.RootedOzFs internally creates new RootedOzoneFileSystem()
• as it looks to me now, this RootedOzoneFileSystem is never closed and it may cause the leak

You are right. RootedOzFs is leaking this internal RootedOzoneFileSystem instance.

By contrast, S3A closes its own internal instance in finalize():

  /**
   * Close the file system; the FileContext API doesn't have an explicit close.
   */
  @Override
  protected void finalize() throws Throwable {
    fsImpl.close();
    super.finalize();
  }

[sadanand48]

By contrast, S3A closes its own internal instance in finalize():

This seems like a good idea, we could do this for Ozone too instead of relying on Hadoop.

[aekom87]

Hi again, thanks for your replies, I've tried the proposed solution

  /**
   * Close the file system; the FileContext API doesn't have an explicit close.
   */
  @Override
  protected void finalize() throws Throwable {
    fsImpl.close();
    super.finalize();
  }

and it does work, memory consumption is stable now. Would it be helpful if I submit a pull request for this? We'd be really glad to have this fix on the 1.4 branch.

[adoroszlai]

Thanks for the feedback. Yes, please feel free to create a PR with the fix for master first, then we'll take care of backporting it to ozone-1.4 branch.

[adoroszlai]

Notes:

1. RootedOzFs has 3 implementations, I guess all need to be fixed.
2. OzFs likely needs similar fix (this is for o3fs:// protocol).

hadoop-ozone/ozonefs-hadoop2/src/main/java/org/apache/hadoop/fs/ozone/OzFs.java
hadoop-ozone/ozonefs-hadoop2/src/main/java/org/apache/hadoop/fs/ozone/RootedOzFs.java
hadoop-ozone/ozonefs-hadoop3/src/main/java/org/apache/hadoop/fs/ozone/OzFs.java
hadoop-ozone/ozonefs-hadoop3/src/main/java/org/apache/hadoop/fs/ozone/RootedOzFs.java
hadoop-ozone/ozonefs/src/main/java/org/apache/hadoop/fs/ozone/OzFs.java
hadoop-ozone/ozonefs/src/main/java/org/apache/hadoop/fs/ozone/RootedOzFs.java

Thanks!

[sadanand48]

Looks similar to the issue I described in https://issues.apache.org/jira/browse/HDDS-11505. In this case, the application didn't properly call close()

If we are suspecting issues in Ozone client itself, HDDS-11543 fixed almost all of the leaks originating from Ozone client.

[xichen01]

@aekom87 Do you have any recent plans to create a PR to fix this issue to master branch?
The ozone-1.4 has backport a lot of patches, and ozone-1.4-rc2 will probably be released in the next few days (Shouldn't be more than next week). if your fix can be merged into master, I would backport it to ozone-1.4.

[aekom87]

Hello, yes, I was working on a PR yesterday but stumbled a bit upon a fact that I probably need a JIRA ticket to create a proper PR (there is corresponding note in PR guidelines and, as far as I checked, all PRs to the master branch have associated JIRA tickets). Since it is not allowed to create tickets for non-members, I wanted to asks how should I proceed with this.

[adoroszlai]

@aekom87 please request a Jira account

[aekom87]

Thanks, PR #7382

[aekom87]

Hi again, I've found another suspicious thing, might be another leak. The 'ratis' JMX metrics folder seems to be growing endlessly

In our case the number of entries increases monotonically ~1k per day and it is not going down upon calling GC
I haven't studied the case deeply yet, but here is the stacktrace
at org.apache.ratis.grpc.metrics.MessageMetrics.createRegistry(MessageMetrics.java:55) at org.apache.ratis.grpc.metrics.MessageMetrics.<init>(MessageMetrics.java:50) at org.apache.ratis.grpc.metrics.intercept.client.MetricClientInterceptor.<init>(MetricClientInterceptor.java:38) at org.apache.ratis.grpc.client.GrpcClientProtocolClient.<init>(GrpcClientProtocolClient.java:105) at org.apache.ratis.grpc.client.GrpcClientRpc.lambda$new$0(GrpcClientRpc.java:59) at org.apache.ratis.grpc.client.GrpcClientRpc$$Lambda$480.1745065685.apply(Unknown Source:-1) at org.apache.ratis.util.PeerProxyMap.createProxyImpl(PeerProxyMap.java:112) at org.apache.ratis.util.PeerProxyMap.access$100(PeerProxyMap.java:42) at org.apache.ratis.util.PeerProxyMap$PeerAndProxy.lambda$getProxy$0(PeerProxyMap.java:70) at org.apache.ratis.util.PeerProxyMap$PeerAndProxy$$Lambda$533.652008838.run(Unknown Source:-1) at org.apache.ratis.util.LifeCycle.startAndTransition(LifeCycle.java:277) at org.apache.ratis.util.PeerProxyMap$PeerAndProxy.getProxy(PeerProxyMap.java:69) at org.apache.ratis.util.PeerProxyMap.getProxy(PeerProxyMap.java:124) at org.apache.ratis.grpc.client.GrpcClientRpc.sendRequestAsync(GrpcClientRpc.java:69) at org.apache.ratis.client.impl.OrderedAsync.sendRequestWithRetry(OrderedAsync.java:206) at org.apache.ratis.client.impl.OrderedAsync$$Lambda$524.1876277700.accept(Unknown Source:-1) at org.apache.ratis.util.SlidingWindow$Client.sendOrDelayRequest(SlidingWindow.java:315) at org.apache.ratis.util.SlidingWindow$Client.submitNewRequest(SlidingWindow.java:294) at org.apache.ratis.client.impl.OrderedAsync.send(OrderedAsync.java:173) at org.apache.ratis.client.impl.OrderedAsync.newInstance(OrderedAsync.java:125) at org.apache.ratis.client.impl.RaftClientImpl.lambda$new$1(RaftClientImpl.java:211) at org.apache.ratis.client.impl.RaftClientImpl$$Lambda$489.1815098946.get(Unknown Source:-1) at org.apache.ratis.util.MemoizedSupplier.get(MemoizedSupplier.java:63) at org.apache.ratis.client.impl.RaftClientImpl.getOrderedAsync(RaftClientImpl.java:279) at org.apache.ratis.client.impl.AsyncImpl.send(AsyncImpl.java:41) at org.apache.ratis.client.impl.AsyncImpl.send(AsyncImpl.java:46) at org.apache.ratis.client.api.AsyncApi.send(AsyncApi.java:46) at org.apache.hadoop.hdds.scm.XceiverClientRatis.lambda$sendRequestAsync$2(XceiverClientRatis.java:237) at org.apache.hadoop.hdds.scm.XceiverClientRatis$$Lambda$508.1044971331.get(Unknown Source:-1) at org.apache.hadoop.hdds.tracing.TracingUtil.executeInSpan(TracingUtil.java:169) at org.apache.hadoop.hdds.tracing.TracingUtil.executeInNewSpan(TracingUtil.java:149) at org.apache.hadoop.hdds.scm.XceiverClientRatis.sendRequestAsync(XceiverClientRatis.java:222) at org.apache.hadoop.hdds.scm.XceiverClientRatis.sendCommandAsync(XceiverClientRatis.java:325) at org.apache.hadoop.hdds.scm.storage.ContainerProtocolCalls.writeChunkAsync(ContainerProtocolCalls.java:423) at org.apache.hadoop.hdds.scm.storage.BlockOutputStream.writeChunkToContainer(BlockOutputStream.java:725) at org.apache.hadoop.hdds.scm.storage.BlockOutputStream.writeChunk(BlockOutputStream.java:543) at org.apache.hadoop.hdds.scm.storage.BlockOutputStream.handleFlushInternal(BlockOutputStream.java:576) at org.apache.hadoop.hdds.scm.storage.BlockOutputStream.handleFlush(BlockOutputStream.java:551) at org.apache.hadoop.hdds.scm.storage.BlockOutputStream.close(BlockOutputStream.java:602) at org.apache.hadoop.ozone.client.io.BlockOutputStreamEntry.close(BlockOutputStreamEntry.java:170) at org.apache.hadoop.ozone.client.io.KeyOutputStream.handleStreamAction(KeyOutputStream.java:513) at org.apache.hadoop.ozone.client.io.KeyOutputStream.handleFlushOrClose(KeyOutputStream.java:487) at org.apache.hadoop.ozone.client.io.KeyOutputStream.close(KeyOutputStream.java:543) at org.apache.hadoop.ozone.client.io.OzoneOutputStream.close(OzoneOutputStream.java:105) at org.apache.hadoop.fs.ozone.OzoneFSOutputStream.close(OzoneFSOutputStream.java:60) at org.apache.hadoop.fs.FSDataOutputStream$PositionCache.close(FSDataOutputStream.java:77) at org.apache.hadoop.fs.FSDataOutputStream.close(FSDataOutputStream.java:106) at org.apache.hadoop.io.IOUtils.copyBytes(IOUtils.java:70) at org.apache.hadoop.io.IOUtils.copyBytes(IOUtils.java:129) at org.apache.hadoop.fs.FileUtil.copy(FileUtil.java:419) at org.apache.hadoop.fs.FileUtil.copy(FileUtil.java:391) at org.apache.hadoop.fs.FileUtil.copy(FileUtil.java:341) at org.apache.spark.deploy.yarn.Client.copyFileToRemote(Client.scala:460) at org.apache.spark.deploy.yarn.Client.prepareLocalResources(Client.scala:774) at org.apache.spark.deploy.yarn.Client.createContainerLaunchContext(Client.scala:982) at org.apache.spark.deploy.yarn.Client.submitApplication(Client.scala:220)

Does this behavior seem wrong to you?

[ivandika3]

@aekom87 Could you kindly raise this in a separate FAQ discussion?

[smileyboy2019]

Is the problem effectively resolved

[spacemonkd]

Hi @aekom87, thanks for pointing out this issue and for the fix (PR #7382).
I saw you had pointed out that the ratis JMX folder keeps growing.

Since the original question has been answered, I am closing this discussion. Please feel free to open a new discussion to target the ratis JMX growth.

@smileyboy2019, I think the original problem has been fixed by #7382