Google-cloud-java: PubSub runs into `java.lang.RuntimeException: ManagedChannel allocation site` when a new publisher is created

[yuri-sergiichuk]

Hi!

We've currently received around 100-200 PubSub related issues when a PubSub publisher is created with the following stacktrace:

io.grpc.internal.ManagedChannelOrphanWrapper$ManagedChannelReference cleanQueue: *~*~*~ Channel ManagedChannelImpl{logId=4613, target=pubsub.googleapis.com:443} was not shutdown properly!!! ~*~*~* (ManagedChannelOrphanWrapper.java:163)
    Make sure to call shutdown()/shutdownNow() and wait until awaitTermination() returns true.
java.lang.RuntimeException: ManagedChannel allocation site
    at io.grpc.internal.ManagedChannelOrphanWrapper$ManagedChannelReference.<init>(ManagedChannelOrphanWrapper.java:103)
    at io.grpc.internal.ManagedChannelOrphanWrapper.<init>(ManagedChannelOrphanWrapper.java:53)
    at io.grpc.internal.ManagedChannelOrphanWrapper.<init>(ManagedChannelOrphanWrapper.java:44)
    at io.grpc.internal.AbstractManagedChannelImplBuilder.build(AbstractManagedChannelImplBuilder.java:410)
    at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.createSingleChannel(InstantiatingGrpcChannelProvider.java:206)
    at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.createChannel(InstantiatingGrpcChannelProvider.java:162)
    at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.getTransportChannel(InstantiatingGrpcChannelProvider.java:149)
    at com.google.api.gax.rpc.ClientContext.create(ClientContext.java:151)
    at com.google.cloud.pubsub.v1.stub.GrpcPublisherStub.create(GrpcPublisherStub.java:161)
    at com.google.cloud.pubsub.v1.Publisher.<init>(Publisher.java:154)
    at com.google.cloud.pubsub.v1.Publisher.<init>(Publisher.java:83)
    at com.google.cloud.pubsub.v1.Publisher$Builder.build(Publisher.java:607)

We are using PubSub library v 1.40.0. And here is how we create publishers:

Publisher createPublisher(ProjectTopicName topicName) {
        try {
            Publisher publisher = Publisher.newBuilder(topicName)
                                           .build();
            return publisher;
        } catch (IOException e) {
            String errorMessage = format("Cannot create a publisher for topic %s", topicName);
            throw new IllegalStateException(errorMessage, e);
        }
    }

Any thoughts or suggestions? By the way, we are running on AppEngine Standard with Java 8.

[pongad]

I don't think this is actually related to creating new Publisher, though gRPC uses that as an opportunity to tell us that we're leaking channels.

Is it possible that you're not calling Publisher.shutdown to clean up properly somewhere?

[yuri-sergiichuk]

Hello @pongad. Thank you for your reply.

No, we are cleaning everything up every time:

private static void cleanupPublisher(Publisher publisher) {
        try {
            publisher.shutdown();
        } catch (Exception e) {
            log().error("Unable to cleanup publisher for topic: {}", publisher.getTopicNameString(), e);
        }
    }

[pongad]

You're right. gRPC wants us to call awaitTermination. I sent a PR for fixing this. Unfortunately, I think this requires users to add awaitTermination to their programs.

[borissnd]

I updated the library and added publisher.awaitTermination(1, TimeUnit.MINUTES); after publisher.shutdown(); in the close() method of my Closeable class but I keep getting the above error on publisher build.
@yuri-sergiichuk, has this patch resolved your issue?

[yuri-sergiichuk]

@borissnd we are testing the new cloud libraries version now. I'll post an update here in case I'll notice the problem again.

[janneh]

@yuri-sergiichuk @borissnd are you still experiencing this issue? I'm seeing the same problem

doing something in the lines of:

val publisher = Publisher.newBuilder(topicName).build()

try {
    messages.forEach { message -> publisher.publish(message) }
} finally {
    publisher.shutdown()
    publisher.awaitTermination(1, TimeUnit.MINUTES)
}

edit: Using version 1.48.0

[yuri-sergiichuk]

Yeah, we do still experience problems.

We are also using 1.48.0 now.

[borissnd]

Same here. The error still persists. I'm using version 1.45.0.
@pongad @snehashah16 , could you please reopen this issue?

[janneh]

Some more info on my problem: it might have been caused by repeatedly creating and shutting down publishers. Which seemed to be the suggested approach from what I found (like github doc and sample code here and here as examples) Could that somehow cause the problem?

Here's a question on that topic: https://github.com/googleapis/google-cloud-java/issues/2342 and there it's suggested to keep a more long lived publisher in a case like that instead. I'm trying that approach now instead.

[yuri-sergiichuk]

@janneh we were trying to cache our publishers, but that had even worse results for us on AppEngine. It's why we are creating and shutting down the subscribers now after usage.
I'd be grateful if you could share the results of your experiments.

[yuri-sergiichuk]

@snehashah16, @pongad, any updates on this issue?

[janneh]

For me changing according to #2342 eliminated the problem. Not a single error of any kind since switching to a lon lived publisher for the service.

[ajaaym]

This is fixed in 628. Will be available after new version of gax-java is released

[cperez1000]

Does anybody know when this will be available?

[menulis]

Exactly the same issue persists for the subscriber channels that do not get shut down properly, since there is no direct or indirect call to GrpcTransportChannel.java#close() from within com.google.cloud.pubsub.v1.Subscriber. Therefore even with google-cloud-pubsub 1.84.0 we keep getting the same error message with slightly different stack trace:

*~*~*~ Channel ManagedChannelImpl{logId=42, target=pubsub.googleapis.com:443} was not shutdown properly!!! ~*~*~*
    Make sure to call shutdown()/shutdownNow() and wait until awaitTermination() returns true.
java.lang.RuntimeException: ManagedChannel allocation site
    at io.grpc.internal.ManagedChannelOrphanWrapper$ManagedChannelReference.<init>(ManagedChannelOrphanWrapper.java:94)
    at io.grpc.internal.ManagedChannelOrphanWrapper.<init>(ManagedChannelOrphanWrapper.java:52)
    at io.grpc.internal.ManagedChannelOrphanWrapper.<init>(ManagedChannelOrphanWrapper.java:43)
    at io.grpc.internal.AbstractManagedChannelImplBuilder.build(AbstractManagedChannelImplBuilder.java:514)
    at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.createSingleChannel(InstantiatingGrpcChannelProvider.java:268)
    at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.createChannel(InstantiatingGrpcChannelProvider.java:185)
    at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.getTransportChannel(InstantiatingGrpcChannelProvider.java:177)
    at com.google.api.gax.rpc.ClientContext.create(ClientContext.java:160)
    at com.google.cloud.pubsub.v1.stub.GrpcSubscriberStub.create(GrpcSubscriberStub.java:263)
    at com.google.cloud.pubsub.v1.Subscriber.doStart(Subscriber.java:261)
    at com.google.api.core.AbstractApiService$InnerService.doStart(AbstractApiService.java:148)
    at com.google.common.util.concurrent.AbstractService.startAsync(AbstractService.java:248)
    at com.google.api.core.AbstractApiService.startAsync(AbstractApiService.java:120)
    at com.google.cloud.pubsub.v1.Subscriber.startAsync(Subscriber.java:253)
   // ...

Is it possible to reopen this issue and fix the problem for the subscriber case?

[lucius-pl]

I've been experiencing the same exception in 1.98.0. A new issue for the subscriber should be opened to expect a fix?