search

opensourceBIM / BIMserver

The open source BIMserver platform
GNU Affero General Public License v3.0
1.56k stars 611 forks source link

Failing download of entities through Java client #946

Open hlg opened 5 years ago

hlg commented 5 years ago

We are using the Java client library and get errors that appear non-deterministic when requesting single entities from the server. E.g. when we call getters of IdEObjects we eventually reach org.bimserver.client.ClientIfcModel.loadExplicit where additional entities are queried. The Server returns a topicId, the client waits for the server to prepare the entity for download and then requests the download using that topicId. At this point, sometimes this happens:

On the server side:

org.bimserver.shared.exceptions.UserException: No data found for topicId 1501
        at org.bimserver.webservices.impl.ServiceImpl.getDownloadData(ServiceImpl.java:352)
        at org.bimserver.servlets.DownloadServlet.service(DownloadServlet.java:173)
        at org.bimserver.servlets.RootServlet.service(RootServlet.java:155)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:857)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1655)
        at org.eclipse.jetty.websocket.server.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:215)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642)
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:533)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1317)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473)
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1219)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
        at org.eclipse.jetty.server.Server.handle(Server.java:531)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:352)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:281)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102)
        at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126)
        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:762)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:680)
        at java.lang.Thread.run(Unknown Source)

Subsequently the output stream gets into an illegal state.

java.lang.IllegalStateException: STREAM
        at org.eclipse.jetty.server.Response.getWriter(Response.java:931)
        at org.bimserver.servlets.DownloadServlet.service(DownloadServlet.java:279)
        at org.bimserver.servlets.RootServlet.service(RootServlet.java:155)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)

This is how it looks on the client side. In this case we are accessing and lazy loading property definitions but it can happen with any entity type.

[main] ERROR org.bimserver.emf.SharedJsonDeserializer -
java.io.EOFException: Unexpected end of ZLIB input stream
        at java.util.zip.InflaterInputStream.fill(InflaterInputStream.java:240)
        at java.util.zip.InflaterInputStream.read(InflaterInputStream.java:158)
        at java.util.zip.GZIPInputStream.read(GZIPInputStream.java:117)
        at org.apache.http.client.entity.LazyDecompressingInputStream.read(LazyDecompressingInputStream.java:73)
        at org.bimserver.utils.CountingInputStream.read(CountingInputStream.java:58)
        at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
        at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
        at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
        at java.io.InputStreamReader.read(InputStreamReader.java:184)
        at java.io.BufferedReader.fill(BufferedReader.java:161)
        at java.io.BufferedReader.read1(BufferedReader.java:212)
        at java.io.BufferedReader.read(BufferedReader.java:286)
        at com.google.gson.stream.JsonReader.fillBuffer(JsonReader.java:1295)
        at com.google.gson.stream.JsonReader.nextNonWhitespace(JsonReader.java:1333)
        at com.google.gson.stream.JsonReader.doPeek(JsonReader.java:549)
        at com.google.gson.stream.JsonReader.peek(JsonReader.java:425)
        at org.bimserver.emf.SharedJsonDeserializer.read(SharedJsonDeserializer.java:115)
        at org.bimserver.client.ClientIfcModel.processDownload(ClientIfcModel.java:599)
        at org.bimserver.client.ClientIfcModel.loadExplicit(ClientIfcModel.java:734)
        at org.bimserver.client.ClientIfcModel.load(ClientIfcModel.java:1046)
        at org.bimserver.emf.IdEObjectImpl.load(IdEObjectImpl.java:126)
        at org.bimserver.emf.IdEObjectImpl.dynamicGet(IdEObjectImpl.java:55)
        at org.eclipse.emf.ecore.impl.EStructuralFeatureImpl$InternalSettingDelegateSingleEObject.dynamicGet(EStructuralFeatureImpl.java:2589)
        at org.eclipse.emf.ecore.impl.BasicEObjectImpl.eGet(BasicEObjectImpl.java:1027)
        at org.eclipse.emf.ecore.impl.BasicEObjectImpl.eGet(BasicEObjectImpl.java:1011)
        at org.eclipse.emf.ecore.impl.BasicEObjectImpl.eGet(BasicEObjectImpl.java:1003)
        at org.bimserver.models.ifc4.impl.IfcRelDefinesByPropertiesImpl.getRelatingPropertyDefinition(IfcRelDefinesByPropertiesImpl.java:96)
        ...

We tried to narrow the conditions of this to happen, assuming that it could be related to the project size, the available server memory or a web client being active in parallel. But none of this proved to allow for consistent reproduction. It seems completely non-deterministic if and when this happens.

Since maintenance of the Java client seems not high priority right now, we understand this may not be resolved in the near future, but if there are any ideas what the cause of this could be, we could aim for a workaround or try to fix it ourselves. Not sure though if this is a Java client issue at all or would happen with other clients as well under similar conditions.

This is happening with 1.5.117. We can currently not test with a newer version due to other issues.

hlg commented 5 years ago

It seems as if this does not appear with deep loading.

rubendel commented 5 years ago

Yes I think for now deep loading is recommended. When we have more time, the client definitely deserves an update.