Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

SessionState IllegalStateException when viewing ticking Table #3162

Closed
cpwright opened this issue Dec 7, 2022 · 5 comments · Fixed by #3169
Closed

SessionState IllegalStateException when viewing ticking Table #3162

cpwright opened this issue Dec 7, 2022 · 5 comments · Fixed by #3169
Assignees
Labels
bug Something isn't working triage
Milestone

Comments

@cpwright
Copy link
Contributor

cpwright commented Dec 7, 2022

Description

I opened a table, and saw this on my console after going for a walk:

        at com.google.common.base.Preconditions.checkState(Preconditions.java:502)
        at io.grpc.internal.ServerCallImpl.closeInternal(ServerCallImpl.java:219)
        at io.grpc.internal.ServerCallImpl.close(ServerCallImpl.java:212)
        at io.grpc.PartialForwardingServerCall.close(PartialForwardingServerCall.java:48)
        at io.grpc.ForwardingServerCall.close(ForwardingServerCall.java:22)
        at io.grpc.ForwardingServerCall$SimpleForwardingServerCall.close(ForwardingServerCall.java:39)
        at io.deephaven.server.session.SessionServiceGrpcImpl$InterceptedCall.close(SessionServiceGrpcImpl.java:257)
        at io.grpc.stub.ServerCalls$ServerCallStreamObserverImpl.onCompleted(ServerCalls.java:395)
        at io.deephaven.server.console.completer.JavaAutoCompleteObserver.onCompleted(JavaAutoCompleteObserver.java:171)
        at io.deephaven.server.browserstreaming.BrowserStream$1.onCompleted(BrowserStream.java:101)
        at io.deephaven.server.browserstreaming.BrowserStream.onComplete(BrowserStream.java:258)
        at io.deephaven.server.browserstreaming.BrowserStream.onMessageReceived(BrowserStream.java:199)
        at io.deephaven.server.util.GrpcServiceOverrideBuilder$BrowserStreamMethod.lambda$invokeNext$2(GrpcServiceOverrideBuilder.java:268)
        at io.deephaven.server.session.SessionState$ExportBuilder.lambda$submit$2(SessionState.java:1349)
        at io.deephaven.server.session.SessionState$ExportObject.doExport(SessionState.java:884)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at io.deephaven.server.runner.DeephavenApiServerModule$ThreadFactory.lambda$newThread$0(DeephavenApiServerModule.java:164)
        at java.lang.Thread.run(Thread.java:829)
        ```
        
**Versions**
 - Deephaven: 0.19
@cpwright cpwright added bug Something isn't working triage labels Dec 7, 2022
@nbauernfeind
Copy link
Member

Investigating, which way did you launch DH?

@nbauernfeind
Copy link
Member

nbauernfeind commented Dec 7, 2022

I'm running a local host jetty instance.

This query ticks for me:

import io.deephaven.engine.util.TableTools
t = TableTools.timeTable("00:00:01").update("V = 1")

Can you share more reproducing steps?

Did you lose the connection to the stream during the walk? Is there any chance that your computer fell asleep?

@niloc132
Copy link
Member

niloc132 commented Dec 7, 2022

From slack, we've confirmed that the app was running using SSL (so h2 via BrowserStream instead of websockets). The stack trace shows BrowserStream.onMessageReceived() line 199, which means that the client set the grpc metadata x-deephaven-stream-halfclose to true. In this context, this means that the client was attempting to half-close the stream, by sending a call to the NextAutoCompleteStream unary, but by the time that the server closed the OpenAutoCompleteStream server-streaming call, it was already closed (likely by the client).

This is a bit surprising, but isn't impossible, and the server make a best effort here to close the "open" server-streaming call, but if it fails not worry about it.

@niloc132 niloc132 self-assigned this Dec 7, 2022
@nbauernfeind nbauernfeind reopened this Dec 7, 2022
@niloc132
Copy link
Member

niloc132 commented Dec 7, 2022

We've confirmed that this happens consistently, but aren't yet clear on if this is a new bug, and if so, why it is only happening now. However, the safelyExecuteLocked fix is not only mask this issue (and in similar cases), but it is also correct to have here for other possible IO problems.

@rcaudy
Copy link
Member

rcaudy commented Dec 8, 2022

This looks similar, although it's from BarrageStreamGenerator instead of the completer. Maybe we've just raised the visibility of some harmless "errors" that show up under race conditions?

        at com.google.common.base.Preconditions.checkState(Preconditions.java:502)
        at io.grpc.internal.ServerCallImpl.sendMessageInternal(ServerCallImpl.java:162)
        at io.grpc.internal.ServerCallImpl.sendMessage(ServerCallImpl.java:154)
        at io.grpc.ForwardingServerCall.sendMessage(ForwardingServerCall.java:32)
        at io.grpc.stub.ServerCalls$ServerCallStreamObserverImpl.onNext(ServerCalls.java:380)
        at io.deephaven.server.barrage.BarrageStreamGenerator.processBatches(BarrageStreamGenerator.java:770)
        at io.deephaven.server.barrage.BarrageStreamGenerator$SubView.forEachStream(BarrageStreamGenerator.java:380)
        at io.deephaven.server.arrow.ArrowModule$1.onNext(ArrowModule.java:46)
        at io.deephaven.server.arrow.ArrowModule$1.onNext(ArrowModule.java:41)
        at io.deephaven.server.barrage.BarrageMessageProducer.propagateToSubscribers(BarrageMessageProducer.java:1546)
        at io.deephaven.server.barrage.BarrageMessageProducer.updateSubscriptionsSnapshotAndPropagate(BarrageMessageProducer.java:1456)
        at io.deephaven.server.barrage.BarrageMessageProducer$UpdatePropagationJob.run(BarrageMessageProducer.java:1025)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
        at java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
        at io.deephaven.server.runner.DeephavenApiServerModule$ThreadFactory.lambda$newThread$0(DeephavenApiServerModule.java:164)
        at java.lang.Thread.run(Thread.java:833)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working triage
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants