search

eclipse-basyx / basyx-java-server-sdk

MIT License
60 stars 47 forks source link

[BUG] Out of Memory Exception #451

Closed mm-mse closed 1 month ago

mm-mse commented 2 months ago

Describe the bug When deployt in Azure Container Apps the environment container runs into a java.lang.OutOfMemoryError: Java heap space exception after a few requests. When reviewing the container I can see that it has a memory consumption of 1.1GB. Compared to an old version (Digest f07ef156cc) using ~500MB that's a huge increase of memory consumption.

To Reproduce Steps to reproduce the behavior:

  1. Deploy current BaSyx Environment container based on image eclipsebasyx/aas-environment:2.0.0-milestone-04
  2. Set Resources of the container to 3Gi and CPU to 1.5
  3. Set environment variables
  4. Request some shells
  5. See error

Expected behavior Less memory consumption for environments that just request the shells from a MongoDB.

BaSyx (please complete the following information):

Screenshots If applicable, add screenshots to help explain your problem.

Used Asset Administration files (.aasx/.json/.xml) Please drop your AAS files here that were used when the bug was encountered.

BaSyx configuration Env variables:

System (please complete the following information):

Additional context The data is stored in a Azure CosmosDB for MongoDB and displayed via the BaSyx WebUI.

Part of the logs:

2024-09-12T13:10:12.406197687Z 2024-09-12T13:10:12.405Z  INFO 1 --- [AAS Environment] [           main] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 1 endpoint beneath base path '/actuator'
2024-09-12T13:10:12.595627866Z 2024-09-12T13:10:12.595Z  INFO 1 --- [AAS Environment] [           main] o.s.i.endpoint.EventDrivenConsumer       : Adding {logging-channel-adapter:_org.springframework.integration.errorLogger} as a subscriber to the 'errorChannel' channel
2024-09-12T13:10:12.595975614Z 2024-09-12T13:10:12.595Z  INFO 1 --- [AAS Environment] [           main] o.s.i.channel.PublishSubscribeChannel    : Channel 'AAS Environment.errorChannel' has 1 subscriber(s).
2024-09-12T13:10:12.596359359Z 2024-09-12T13:10:12.596Z  INFO 1 --- [AAS Environment] [           main] o.s.i.endpoint.EventDrivenConsumer       : started bean '_org.springframework.integration.errorLogger'
2024-09-12T13:10:12.670413087Z 2024-09-12T13:10:12.669Z  INFO 1 --- [AAS Environment] [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port 8081 (http) with context path '/'
2024-09-12T13:10:12.690969452Z 2024-09-12T13:10:12.690Z  INFO 1 --- [AAS Environment] [           main] o.e.d.b.a.c.AasEnvironmentComponent      : Started AasEnvironmentComponent in 12.829 seconds (process running for 13.819)
2024-09-12T13:11:56.241047320Z 2024-09-12T13:11:56.240Z  INFO 1 --- [AAS Environment] [nio-8081-exec-6] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2024-09-12T13:11:56.241816072Z 2024-09-12T13:11:56.241Z  INFO 1 --- [AAS Environment] [nio-8081-exec-6] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2024-09-12T13:11:56.243243956Z 2024-09-12T13:11:56.243Z  INFO 1 --- [AAS Environment] [nio-8081-exec-6] o.s.web.servlet.DispatcherServlet        : Completed initialization in 1 ms
2024-09-12T13:12:27.603928625Z 2024-09-12T13:12:27.589Z ERROR 1 --- [AAS Environment] [nio-8081-exec-3] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed: org.springframework.dao.InvalidDataAccessResourceUsageException: Unexpected exception] with root cause
2024-09-12T13:12:27.603969692Z 
2024-09-12T13:12:27.603980722Z java.lang.OutOfMemoryError: Java heap space
2024-09-12T13:12:27.603989689Z  at java.base/java.nio.HeapByteBuffer.<init>(HeapByteBuffer.java:64) ~[na:na]
2024-09-12T13:12:27.603996281Z  at java.base/java.nio.ByteBuffer.allocate(ByteBuffer.java:363) ~[na:na]
2024-09-12T13:12:27.604004336Z  at com.mongodb.internal.connection.PowerOfTwoBufferPool.createNew(PowerOfTwoBufferPool.java:126) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604011540Z  at com.mongodb.internal.connection.PowerOfTwoBufferPool.getByteBuffer(PowerOfTwoBufferPool.java:118) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604018172Z  at com.mongodb.internal.connection.PowerOfTwoBufferPool.getBuffer(PowerOfTwoBufferPool.java:113) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604025556Z  at com.mongodb.internal.connection.SocketStream.read(SocketStream.java:171) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604032458Z  at com.mongodb.internal.connection.SocketStream.read(SocketStream.java:196) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604040654Z  at com.mongodb.internal.connection.InternalStreamConnection.receiveResponseBuffers(InternalStreamConnection.java:724) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604049490Z  at com.mongodb.internal.connection.InternalStreamConnection.receiveMessageWithAdditionalTimeout(InternalStreamConnection.java:580) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604056634Z  at com.mongodb.internal.connection.InternalStreamConnection.receiveCommandMessageResponse(InternalStreamConnection.java:428) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604063617Z  at com.mongodb.internal.connection.InternalStreamConnection.sendAndReceive(InternalStreamConnection.java:354) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604070449Z  at com.mongodb.internal.connection.UsageTrackingInternalConnection.sendAndReceive(UsageTrackingInternalConnection.java:114) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604077352Z  at com.mongodb.internal.connection.DefaultConnectionPool$PooledConnection.sendAndReceive(DefaultConnectionPool.java:743) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604084606Z  at com.mongodb.internal.connection.CommandProtocolImpl.execute(CommandProtocolImpl.java:76) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604091499Z  at com.mongodb.internal.connection.DefaultServer$DefaultServerProtocolExecutor.execute(DefaultServer.java:209) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604098672Z  at com.mongodb.internal.connection.DefaultServerConnection.executeProtocol(DefaultServerConnection.java:115) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604105805Z  at com.mongodb.internal.connection.DefaultServerConnection.command(DefaultServerConnection.java:83) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604127075Z  at com.mongodb.internal.connection.DefaultServerConnection.command(DefaultServerConnection.java:74) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604133898Z  at com.mongodb.internal.connection.DefaultServer$OperationCountTrackingConnection.command(DefaultServer.java:299) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604140811Z  at com.mongodb.internal.operation.CommandBatchCursor.lambda$getMore$1(CommandBatchCursor.java:231) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604147954Z  at com.mongodb.internal.operation.CommandBatchCursor$$Lambda$1753/0x000073aeec8de628.accept(Unknown Source) ~[na:na]
2024-09-12T13:12:27.604154656Z  at com.mongodb.internal.operation.CommandBatchCursor$ResourceManager.executeWithConnection(CommandBatchCursor.java:315) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604161469Z  at com.mongodb.internal.operation.CommandBatchCursor.getMore(CommandBatchCursor.java:226) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604168021Z  at com.mongodb.internal.operation.CommandBatchCursor.doHasNext(CommandBatchCursor.java:105) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604174784Z  at com.mongodb.internal.operation.CommandBatchCursor$$Lambda$1688/0x000073aeec8aa000.get(Unknown Source) ~[na:na]
2024-09-12T13:12:27.604182408Z  at com.mongodb.internal.operation.CommandBatchCursor$ResourceManager.execute(CommandBatchCursor.java:278) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604189281Z  at com.mongodb.internal.operation.CommandBatchCursor.hasNext(CommandBatchCursor.java:96) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.604209348Z  at com.mongodb.client.internal.MongoBatchCursorAdapter.hasNext(MongoBatchCursorAdapter.java:52) ~[mongodb-driver-sync-5.0.1.jar!/:na]
2024-09-12T13:12:27.604217373Z  at org.springframework.data.mongodb.core.MongoTemplate.executeFindMultiInternal(MongoTemplate.java:2925) ~[spring-data-mongodb-4.3.2.jar!/:4.3.2]
2024-09-12T13:12:27.604224777Z  at org.springframework.data.mongodb.core.MongoTemplate.doFind(MongoTemplate.java:2604) ~[spring-data-mongodb-4.3.2.jar!/:4.3.2]
2024-09-12T13:12:27.604232562Z  at org.springframework.data.mongodb.core.MongoTemplate.doFind(MongoTemplate.java:2583) ~[spring-data-mongodb-4.3.2.jar!/:4.3.2]
2024-09-12T13:12:27.604240236Z  at org.springframework.data.mongodb.core.MongoTemplate.find(MongoTemplate.java:868) ~[spring-data-mongodb-4.3.2.jar!/:4.3.2]
2024-09-12T13:12:27.604246978Z 
2024-09-12T13:12:27.654373337Z 2024-09-12T13:12:27.586Z ERROR 1 --- [AAS Environment] [nio-8081-exec-4] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Handler dispatch failed: java.lang.OutOfMemoryError: Java heap space] with root cause
2024-09-12T13:12:27.661216247Z 
2024-09-12T13:12:27.661539038Z java.lang.OutOfMemoryError: Java heap space
2024-09-12T13:12:27.662794024Z  at java.base/java.util.HashMap.resize(HashMap.java:702) ~[na:na]
2024-09-12T13:12:27.662810815Z  at java.base/java.util.HashMap.putVal(HashMap.java:627) ~[na:na]
2024-09-12T13:12:27.662819591Z  at java.base/java.util.HashMap.put(HashMap.java:610) ~[na:na]
2024-09-12T13:12:27.662826374Z  at org.bson.Document.put(Document.java:490) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662833417Z  at org.bson.codecs.DocumentCodec.decode(DocumentCodec.java:176) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662839960Z  at org.bson.codecs.DocumentCodec.decode(DocumentCodec.java:44) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662846982Z  at org.bson.internal.LazyCodec.decode(LazyCodec.java:53) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662855108Z  at org.bson.codecs.ContainerCodecHelper.readValue(ContainerCodecHelper.java:65) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662871999Z  at org.bson.codecs.DocumentCodec.decode(DocumentCodec.java:176) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662878601Z  at org.bson.codecs.DocumentCodec.decode(DocumentCodec.java:44) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662884933Z  at org.bson.internal.LazyCodec.decode(LazyCodec.java:53) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662891726Z  at org.bson.codecs.ContainerCodecHelper.readValue(ContainerCodecHelper.java:65) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662898388Z  at org.bson.codecs.CollectionCodec.readValue(CollectionCodec.java:86) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662904750Z  at org.bson.codecs.AbstractCollectionCodec.decode(AbstractCollectionCodec.java:95) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662911393Z  at org.bson.codecs.AbstractCollectionCodec.decode(AbstractCollectionCodec.java:42) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662918025Z  at org.bson.codecs.ContainerCodecHelper.readValue(ContainerCodecHelper.java:65) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662924848Z  at org.bson.codecs.DocumentCodec.decode(DocumentCodec.java:176) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662931600Z  at org.bson.codecs.DocumentCodec.decode(DocumentCodec.java:44) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662938553Z  at org.bson.internal.LazyCodec.decode(LazyCodec.java:53) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662945205Z  at org.bson.codecs.ContainerCodecHelper.readValue(ContainerCodecHelper.java:65) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662951778Z  at org.bson.codecs.CollectionCodec.readValue(CollectionCodec.java:86) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662958320Z  at org.bson.codecs.AbstractCollectionCodec.decode(AbstractCollectionCodec.java:95) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662965333Z  at org.bson.codecs.AbstractCollectionCodec.decode(AbstractCollectionCodec.java:42) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662972687Z  at org.bson.codecs.ContainerCodecHelper.readValue(ContainerCodecHelper.java:65) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662980231Z  at org.bson.codecs.DocumentCodec.decode(DocumentCodec.java:176) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662987735Z  at org.bson.codecs.DocumentCodec.decode(DocumentCodec.java:44) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.662996171Z  at com.mongodb.internal.operation.CommandResultArrayCodec.decode(CommandResultArrayCodec.java:52) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.663004536Z  at com.mongodb.internal.operation.CommandResultDocumentCodec.readValue(CommandResultDocumentCodec.java:60) ~[mongodb-driver-core-5.0.1.jar!/:na]
2024-09-12T13:12:27.663011569Z  at org.bson.codecs.BsonDocumentCodec.decode(BsonDocumentCodec.java:87) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.663018262Z  at org.bson.codecs.BsonDocumentCodec.decode(BsonDocumentCodec.java:42) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.663025134Z  at org.bson.internal.LazyCodec.decode(LazyCodec.java:53) ~[bson-5.0.1.jar!/:na]
2024-09-12T13:12:27.663032248Z  at org.bson.codecs.BsonDocumentCodec.readValue(BsonDocumentCodec.java:104) ~[bson-5.0.1.jar!/:na]
FriedJannik commented 2 months ago

Hello @mm-mse, I was unable to reproduce the issue you encounter If you could share the amount of AAS that are stored in your MongoDB we could investigate the issue further.

mm-mse commented 1 month ago

Sorry I could also not reproduce it again using a newer setup.