Skip to content

PubSub: subscriber.stopAsync().awaitTerminated() does not destroy respective threads #22

New issue
New issue
Closed
#74
Closed
PubSub: subscriber.stopAsync().awaitTerminated() does not destroy respective threads#22
#74
Assignees
maitrimangal
Labels
🚨This issue needs some love.api: pubsubIssues related to the googleapis/java-pubsub API.priority: p2Moderately-important priority. Fix may not be included in next release.type: bugError or flaw in code with unintended results or allowing sub-optimal usage patterns.
@menulis

Description

@menulis
menulis
opened on May 28, 2019

Environment details

OS type and version: macOS 10.14.5 / Debian 4.9.168-1 (App Engine Flex)
Java version: Oracle 1.8.0_181 / openjdk version "1.8.0_212"
google-cloud-java version: 1.75.0

Steps to reproduce

  1. Create a subscriber, call startAsync() followed by stopAsync() as per documentation
  2. Observe the number of threads before and after calling stopAsync()
  3. The number of threads is growing

Code example

import com.google.api.gax.core.ExecutorProvider
import com.google.api.gax.core.FixedExecutorProvider
import com.google.cloud.ServiceOptions
import com.google.cloud.pubsub.v1.Subscriber
import com.google.pubsub.v1.ProjectSubscriptionName
import java.util.concurrent.Executors
import java.util.concurrent.TimeUnit

fun main() {
    val subscriptionName = ProjectSubscriptionName.of(
        ServiceOptions.getDefaultProjectId(), "test"
    )

    for (x in 1..2) {
        var i = 0
        val subscriber = Subscriber.newBuilder(subscriptionName)
            { message, consumer -> consumer.ack() }
            .build()
        println("$x/${++i}: ${Thread.activeCount()}: ${Thread.getAllStackTraces().entries.map { it.key.name }}")
        subscriber.startAsync().awaitRunning()
        println("$x/${++i}: ${Thread.activeCount()}: ${Thread.getAllStackTraces().entries.map { it.key.name }}")
        subscriber.stopAsync().awaitTerminated()
        println("$x/${++i}: ${Thread.activeCount()}: ${Thread.getAllStackTraces().entries.map { it.key.name }}")
    }

    for (x in 3..8) {
        var i = 0
        val executorProvider: ExecutorProvider =
            FixedExecutorProvider.create(Executors.newSingleThreadScheduledExecutor())
        val subscriber = Subscriber.newBuilder(subscriptionName)
        { message, consumer -> consumer.ack() }
            .setExecutorProvider(executorProvider)
            .setSystemExecutorProvider(executorProvider)
            .build()
        subscriber.startAsync().awaitRunning()
        println("$x/${++i}: ${Thread.activeCount()}: ${Thread.getAllStackTraces().entries.map { it.key.name }}")
        subscriber.stopAsync().awaitTerminated()
        println("$x/${++i}: ${Thread.activeCount()}: ${Thread.getAllStackTraces().entries.map { it.key.name }}")
        executorProvider.executor.shutdown()
        println("$x/${++i}: ${Thread.activeCount()}: ${Thread.getAllStackTraces().entries.map { it.key.name }}")
        if (!executorProvider.executor.awaitTermination(5000, TimeUnit.MILLISECONDS)) {
            val hangingTasks = executorProvider.executor.shutdownNow()
            println("Hanging tasks: $hangingTasks")
        }
        println("$x/${++i}: ${Thread.activeCount()}: ${Thread.getAllStackTraces().entries}")
    }
}

Expected results

The number of active threads before calling startAsync() and after calling stopAsync() shall be equal.

Actual results

When not explicitly providing executor providers, calling startAsync() created five threads and calling stopAsync() does not stop any of them.

When providing Executors.newSingleThreadScheduledExecutor() as executorProvider and systemExecutorProvider and explicitly calling shutdown() on the executor, the result is "better" in a way that the number of threads grow much slower, but it still grows. Further, if three or more such subscribers with a custom executor provider are started and stopped, "ManagedChannel allocation site ("was not shutdown properly") exceptions appear, which suggests that the underlying gRPC state is not being cleaned up properly upon stopAsync().

1/1: 2: [Monitor Ctrl-Break, Finalizer, Reference Handler, main, Signal Dispatcher]
1/2: 7: [grpc-default-worker-ELG-1-1, pool-1-thread-2, Attach Listener, grpc-default-executor-0, Monitor Ctrl-Break, pool-1-thread-3, pool-1-thread-1, Finalizer, Reference Handler, main, Signal Dispatcher]
1/3: 9: [grpc-default-worker-ELG-1-1, pool-1-thread-5, pool-1-thread-2, Attach Listener, Monitor Ctrl-Break, main, Signal Dispatcher, grpc-default-executor-0, pool-1-thread-4, pool-1-thread-3, pool-1-thread-1, Finalizer, Reference Handler]
2/1: 9: [grpc-default-worker-ELG-1-1, pool-1-thread-5, pool-1-thread-2, Attach Listener, Monitor Ctrl-Break, main, Signal Dispatcher, grpc-default-executor-0, pool-1-thread-4, pool-1-thread-3, pool-1-thread-1, Finalizer, Reference Handler]
2/2: 14: [grpc-default-worker-ELG-1-1, pool-1-thread-5, pool-1-thread-2, pool-4-thread-2, Attach Listener, Monitor Ctrl-Break, grpc-default-executor-1, main, Signal Dispatcher, pool-4-thread-3, grpc-default-worker-ELG-1-2, grpc-default-executor-0, pool-1-thread-4, pool-4-thread-1, pool-1-thread-3, pool-1-thread-1, Finalizer, Reference Handler]
2/3: 16: [grpc-default-worker-ELG-1-1, pool-1-thread-5, pool-1-thread-2, pool-4-thread-2, Attach Listener, pool-4-thread-4, Monitor Ctrl-Break, grpc-default-executor-1, main, Signal Dispatcher, pool-4-thread-3, grpc-default-worker-ELG-1-2, grpc-default-executor-0, pool-1-thread-4, pool-4-thread-5, pool-4-thread-1, pool-1-thread-3, pool-1-thread-1, Finalizer, Reference Handler]
3/1: 19: [grpc-default-worker-ELG-1-1, grpc-default-worker-ELG-1-3, pool-1-thread-5, pool-1-thread-2, grpc-default-executor-2, pool-4-thread-2, Attach Listener, pool-4-thread-4, Monitor Ctrl-Break, grpc-default-executor-1, main, Signal Dispatcher, pool-4-thread-3, grpc-default-worker-ELG-1-2, grpc-default-executor-0, pool-1-thread-4, pool-4-thread-5, pool-6-thread-1, pool-4-thread-1, pool-1-thread-3, pool-1-thread-1, Finalizer, Reference Handler]
3/2: 19: [grpc-default-worker-ELG-1-1, grpc-default-worker-ELG-1-3, pool-1-thread-5, pool-1-thread-2, grpc-default-executor-2, pool-4-thread-2, Attach Listener, pool-4-thread-4, Monitor Ctrl-Break, grpc-default-executor-1, main, Signal Dispatcher, pool-4-thread-3, grpc-default-worker-ELG-1-2, grpc-default-executor-0, pool-1-thread-4, pool-4-thread-5, pool-6-thread-1, pool-4-thread-1, pool-1-thread-3, pool-1-thread-1, Finalizer, Reference Handler]
3/3: 19: [grpc-default-worker-ELG-1-1, grpc-default-worker-ELG-1-3, pool-1-thread-5, pool-1-thread-2, grpc-default-executor-2, pool-4-thread-2, Attach Listener, pool-4-thread-4, Monitor Ctrl-Break, grpc-default-executor-1, main, Signal Dispatcher, pool-4-thread-3, grpc-default-worker-ELG-1-2, grpc-default-executor-0, pool-1-thread-4, pool-4-thread-5, pool-6-thread-1, pool-4-thread-1, pool-1-thread-3, pool-1-thread-1, Finalizer, Reference Handler]
3/4: 18: [Thread[grpc-default-worker-ELG-1-1,5,main]=[Ljava.lang.StackTraceElement;@609db546, Thread[grpc-default-worker-ELG-1-3,5,main]=[Ljava.lang.StackTraceElement;@20f5281c, Thread[pool-1-thread-5,5,main]=[Ljava.lang.StackTraceElement;@56c4278e, Thread[pool-1-thread-2,5,main]=[Ljava.lang.StackTraceElement;@301eda63, Thread[grpc-default-executor-2,5,main]=[Ljava.lang.StackTraceElement;@3d246ea3, Thread[pool-4-thread-2,5,main]=[Ljava.lang.StackTraceElement;@341814d3, Thread[Attach Listener,9,system]=[Ljava.lang.StackTraceElement;@4397ad89, Thread[pool-4-thread-4,5,main]=[Ljava.lang.StackTraceElement;@59cba5a, Thread[Monitor Ctrl-Break,5,main]=[Ljava.lang.StackTraceElement;@1bd39d3c, Thread[grpc-default-executor-1,5,main]=[Ljava.lang.StackTraceElement;@6f19ac19, Thread[main,5,main]=[Ljava.lang.StackTraceElement;@119cbf96, Thread[Signal Dispatcher,9,system]=[Ljava.lang.StackTraceElement;@71329995, Thread[pool-4-thread-3,5,main]=[Ljava.lang.StackTraceElement;@768fc0f2, Thread[grpc-default-worker-ELG-1-2,5,main]=[Ljava.lang.StackTraceElement;@5454d35e, Thread[grpc-default-executor-0,5,main]=[Ljava.lang.StackTraceElement;@20c0a64d, Thread[pool-1-thread-4,5,main]=[Ljava.lang.StackTraceElement;@455b6df1, Thread[pool-4-thread-5,5,main]=[Ljava.lang.StackTraceElement;@4ddbbdf8, Thread[pool-4-thread-1,5,main]=[Ljava.lang.StackTraceElement;@3f67593e, Thread[pool-1-thread-3,5,main]=[Ljava.lang.StackTraceElement;@1ab06251, Thread[pool-1-thread-1,5,main]=[Ljava.lang.StackTraceElement;@41ab013, Thread[Finalizer,8,system]=[Ljava.lang.StackTraceElement;@14bee915, Thread[Reference Handler,10,system]=[Ljava.lang.StackTraceElement;@1115ec15]
4/1: 21: [pool-1-thread-5, grpc-default-executor-2, grpc-default-worker-ELG-1-4, pool-4-thread-2, pool-4-thread-4, Monitor Ctrl-Break, grpc-default-executor-1, main, pool-4-thread-3, pool-1-thread-4, pool-4-thread-5, grpc-default-executor-3, pool-4-thread-1, pool-1-thread-1, grpc-default-worker-ELG-1-1, grpc-default-worker-ELG-1-3, pool-1-thread-2, Attach Listener, Signal Dispatcher, grpc-default-worker-ELG-1-2, grpc-default-executor-0, pool-1-thread-3, Finalizer, Reference Handler, pool-8-thread-1]
4/2: 21: [pool-1-thread-5, grpc-default-executor-2, grpc-default-worker-ELG-1-4, pool-4-thread-2, pool-4-thread-4, Monitor Ctrl-Break, grpc-default-executor-1, main, pool-4-thread-3, pool-1-thread-4, pool-4-thread-5, grpc-default-executor-3, pool-4-thread-1, pool-1-thread-1, grpc-default-worker-ELG-1-1, grpc-default-worker-ELG-1-3, pool-1-thread-2, Attach Listener, Signal Dispatcher, grpc-default-worker-ELG-1-2, grpc-default-executor-0, pool-1-thread-3, Finalizer, Reference Handler, pool-8-thread-1]
4/3: 21: [pool-1-thread-5, grpc-default-executor-2, grpc-default-worker-ELG-1-4, pool-4-thread-2, pool-4-thread-4, Monitor Ctrl-Break, grpc-default-executor-1, main, pool-4-thread-3, pool-1-thread-4, pool-4-thread-5, grpc-default-executor-3, pool-4-thread-1, pool-1-thread-1, grpc-default-worker-ELG-1-1, grpc-default-worker-ELG-1-3, pool-1-thread-2, Attach Listener, Signal Dispatcher, grpc-default-worker-ELG-1-2, grpc-default-executor-0, pool-1-thread-3, Finalizer, Reference Handler, pool-8-thread-1]
4/4: 20: [Thread[grpc-default-worker-ELG-1-1,5,main]=[Ljava.lang.StackTraceElement;@58ce9668, Thread[grpc-default-worker-ELG-1-3,5,main]=[Ljava.lang.StackTraceElement;@172b013, Thread[pool-1-thread-5,5,main]=[Ljava.lang.StackTraceElement;@56673b2c, Thread[pool-1-thread-2,5,main]=[Ljava.lang.StackTraceElement;@2796aeae, Thread[grpc-default-executor-2,5,main]=[Ljava.lang.StackTraceElement;@b4711e2, Thread[grpc-default-worker-ELG-1-4,5,main]=[Ljava.lang.StackTraceElement;@1fa1cab1, Thread[pool-4-thread-2,5,main]=[Ljava.lang.StackTraceElement;@70f02c32, Thread[Attach Listener,9,system]=[Ljava.lang.StackTraceElement;@62010f5c, Thread[pool-4-thread-4,5,main]=[Ljava.lang.StackTraceElement;@51fadaff, Thread[Monitor Ctrl-Break,5,main]=[Ljava.lang.StackTraceElement;@401f7633, Thread[grpc-default-executor-1,5,main]=[Ljava.lang.StackTraceElement;@31ff43be, Thread[main,5,main]=[Ljava.lang.StackTraceElement;@5b6ec132, Thread[Signal Dispatcher,9,system]=[Ljava.lang.StackTraceElement;@5c44c582, Thread[pool-4-thread-3,5,main]=[Ljava.lang.StackTraceElement;@67d18ed7, Thread[grpc-default-worker-ELG-1-2,5,main]=[Ljava.lang.StackTraceElement;@2c78d320, Thread[grpc-default-executor-0,5,main]=[Ljava.lang.StackTraceElement;@132e0cc, Thread[pool-1-thread-4,5,main]=[Ljava.lang.StackTraceElement;@7b205dbd, Thread[pool-4-thread-5,5,main]=[Ljava.lang.StackTraceElement;@106cc338, Thread[grpc-default-executor-3,5,main]=[Ljava.lang.StackTraceElement;@7a67e3c6, Thread[pool-4-thread-1,5,main]=[Ljava.lang.StackTraceElement;@6cc558c6, Thread[pool-1-thread-3,5,main]=[Ljava.lang.StackTraceElement;@15713d56, Thread[pool-1-thread-1,5,main]=[Ljava.lang.StackTraceElement;@63f259c3, Thread[Finalizer,8,system]=[Ljava.lang.StackTraceElement;@26ceffa8, Thread[Reference Handler,10,system]=[Ljava.lang.StackTraceElement;@600b90df]
5/1: 23: [pool-1-thread-5, grpc-default-executor-2, grpc-default-worker-ELG-1-4, pool-4-thread-2, pool-4-thread-4, Monitor Ctrl-Break, grpc-default-executor-1, main, pool-4-thread-3, pool-1-thread-4, grpc-default-executor-4, pool-4-thread-5, grpc-default-executor-3, pool-4-thread-1, pool-1-thread-1, grpc-default-worker-ELG-1-1, grpc-default-worker-ELG-1-3, pool-1-thread-2, Attach Listener, pool-10-thread-1, Signal Dispatcher, grpc-default-worker-ELG-1-2, grpc-default-executor-0, grpc-default-worker-ELG-1-5, pool-1-thread-3, Finalizer, Reference Handler]
5/2: 23: [pool-1-thread-5, grpc-default-executor-2, grpc-default-worker-ELG-1-4, pool-4-thread-2, pool-4-thread-4, Monitor Ctrl-Break, grpc-default-executor-1, main, pool-4-thread-3, pool-1-thread-4, grpc-default-executor-4, pool-4-thread-5, grpc-default-executor-3, pool-4-thread-1, pool-1-thread-1, grpc-default-worker-ELG-1-1, grpc-default-worker-ELG-1-3, pool-1-thread-2, Attach Listener, pool-10-thread-1, Signal Dispatcher, grpc-default-worker-ELG-1-2, grpc-default-executor-0, grpc-default-worker-ELG-1-5, pool-1-thread-3, Finalizer, Reference Handler]
5/3: 22: [pool-1-thread-5, grpc-default-executor-2, grpc-default-worker-ELG-1-4, pool-4-thread-2, pool-4-thread-4, Monitor Ctrl-Break, grpc-default-executor-1, main, pool-4-thread-3, pool-1-thread-4, grpc-default-executor-4, pool-4-thread-5, grpc-default-executor-3, pool-4-thread-1, pool-1-thread-1, grpc-default-worker-ELG-1-1, grpc-default-worker-ELG-1-3, pool-1-thread-2, Attach Listener, Signal Dispatcher, grpc-default-worker-ELG-1-2, grpc-default-executor-0, grpc-default-worker-ELG-1-5, pool-1-thread-3, Finalizer, Reference Handler]
5/4: 22: [Thread[pool-1-thread-5,5,main]=[Ljava.lang.StackTraceElement;@22f31dec, Thread[grpc-default-executor-2,5,main]=[Ljava.lang.StackTraceElement;@34c01041, Thread[grpc-default-worker-ELG-1-4,5,main]=[Ljava.lang.StackTraceElement;@76f4b65, Thread[pool-4-thread-2,5,main]=[Ljava.lang.StackTraceElement;@c94fd30, Thread[pool-4-thread-4,5,main]=[Ljava.lang.StackTraceElement;@36328d33, Thread[Monitor Ctrl-Break,5,main]=[Ljava.lang.StackTraceElement;@2c4d1ac, Thread[grpc-default-executor-1,5,main]=[Ljava.lang.StackTraceElement;@7f0d96f2, Thread[main,5,main]=[Ljava.lang.StackTraceElement;@545b995e, Thread[pool-4-thread-3,5,main]=[Ljava.lang.StackTraceElement;@76a2ddf3, Thread[pool-1-thread-4,5,main]=[Ljava.lang.StackTraceElement;@524f3b3a, Thread[grpc-default-executor-4,5,main]=[Ljava.lang.StackTraceElement;@41e68d87, Thread[pool-4-thread-5,5,main]=[Ljava.lang.StackTraceElement;@49ff7d8c, Thread[grpc-default-executor-3,5,main]=[Ljava.lang.StackTraceElement;@29526c05, Thread[pool-4-thread-1,5,main]=[Ljava.lang.StackTraceElement;@2ef14fe, Thread[pool-1-thread-1,5,main]=[Ljava.lang.StackTraceElement;@77102b91, Thread[grpc-default-worker-ELG-1-1,5,main]=[Ljava.lang.StackTraceElement;@45312be2, Thread[grpc-default-worker-ELG-1-3,5,main]=[Ljava.lang.StackTraceElement;@7fb95505, Thread[pool-1-thread-2,5,main]=[Ljava.lang.StackTraceElement;@58be6e8, Thread[Attach Listener,9,system]=[Ljava.lang.StackTraceElement;@7331196b, Thread[Signal Dispatcher,9,system]=[Ljava.lang.StackTraceElement;@3f9342d4, Thread[grpc-default-worker-ELG-1-2,5,main]=[Ljava.lang.StackTraceElement;@ab7395e, Thread[grpc-default-executor-0,5,main]=[Ljava.lang.StackTraceElement;@50d13246, Thread[grpc-default-worker-ELG-1-5,5,main]=[Ljava.lang.StackTraceElement;@2bd08376, Thread[pool-1-thread-3,5,main]=[Ljava.lang.StackTraceElement;@e70f13a, Thread[Finalizer,8,system]=[Ljava.lang.StackTraceElement;@3d3e5463, Thread[Reference Handler,10,system]=[Ljava.lang.StackTraceElement;@64a40280]
Geg 28, 2019 8:11:54 PM io.grpc.internal.ManagedChannelOrphanWrapper$ManagedChannelReference cleanQueue
SEVERE: *~*~*~ Channel ManagedChannelImpl{logId=9, 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:449)
	at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.createSingleChannel(InstantiatingGrpcChannelProvider.java:223)
	at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.createChannel(InstantiatingGrpcChannelProvider.java:164)
	at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.getTransportChannel(InstantiatingGrpcChannelProvider.java:156)
	at com.google.api.gax.rpc.ClientContext.create(ClientContext.java:157)
	at com.google.cloud.pubsub.v1.stub.GrpcSubscriberStub.create(GrpcSubscriberStub.java:263)
	at com.google.cloud.pubsub.v1.Subscriber.doStart(Subscriber.java:268)
	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:260)
	at TestKt.main(Test.kt:33)
	at TestKt.main(Test.kt)

Geg 28, 2019 8:11:54 PM io.grpc.internal.ManagedChannelOrphanWrapper$ManagedChannelReference cleanQueue
SEVERE: *~*~*~ Channel ManagedChannelImpl{logId=1, 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:449)
	at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.createSingleChannel(InstantiatingGrpcChannelProvider.java:223)
	at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.createChannel(InstantiatingGrpcChannelProvider.java:164)
	at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.getTransportChannel(InstantiatingGrpcChannelProvider.java:156)
	at com.google.api.gax.rpc.ClientContext.create(ClientContext.java:157)
	at com.google.cloud.pubsub.v1.stub.GrpcSubscriberStub.create(GrpcSubscriberStub.java:263)
	at com.google.cloud.pubsub.v1.Subscriber.doStart(Subscriber.java:268)
	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:260)
	at TestKt.main(Test.kt:18)
	at TestKt.main(Test.kt)

Geg 28, 2019 8:11:54 PM io.grpc.internal.ManagedChannelOrphanWrapper$ManagedChannelReference cleanQueue
SEVERE: *~*~*~ Channel ManagedChannelImpl{logId=16, 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:449)
	at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.createSingleChannel(InstantiatingGrpcChannelProvider.java:223)
	at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.createChannel(InstantiatingGrpcChannelProvider.java:164)
	at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.getTransportChannel(InstantiatingGrpcChannelProvider.java:156)
	at com.google.api.gax.rpc.ClientContext.create(ClientContext.java:157)
	at com.google.cloud.pubsub.v1.stub.GrpcSubscriberStub.create(GrpcSubscriberStub.java:263)
	at com.google.cloud.pubsub.v1.Subscriber.doStart(Subscriber.java:268)
	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:260)
	at TestKt.main(Test.kt:33)
	at TestKt.main(Test.kt)

Geg 28, 2019 8:11:54 PM io.grpc.internal.ManagedChannelOrphanWrapper$ManagedChannelReference cleanQueue
SEVERE: *~*~*~ Channel ManagedChannelImpl{logId=5, 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:449)
	at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.createSingleChannel(InstantiatingGrpcChannelProvider.java:223)
	at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.createChannel(InstantiatingGrpcChannelProvider.java:164)
	at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.getTransportChannel(InstantiatingGrpcChannelProvider.java:156)
	at com.google.api.gax.rpc.ClientContext.create(ClientContext.java:157)
	at com.google.cloud.pubsub.v1.stub.GrpcSubscriberStub.create(GrpcSubscriberStub.java:263)
	at com.google.cloud.pubsub.v1.Subscriber.doStart(Subscriber.java:268)
	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:260)
	at TestKt.main(Test.kt:18)
	at TestKt.main(Test.kt)

6/1: 25: [pool-1-thread-5, grpc-default-executor-5, grpc-default-executor-2, grpc-default-worker-ELG-1-4, pool-4-thread-2, pool-4-thread-4, Monitor Ctrl-Break, grpc-default-executor-1, main, pool-4-thread-3, pool-1-thread-4, grpc-default-executor-4, pool-4-thread-5, grpc-default-executor-3, pool-4-thread-1, pool-1-thread-1, grpc-default-worker-ELG-1-1, grpc-default-worker-ELG-1-3, pool-1-thread-2, Attach Listener, Signal Dispatcher, pool-12-thread-1, grpc-default-worker-ELG-1-2, grpc-default-worker-ELG-1-6, grpc-default-executor-0, grpc-default-worker-ELG-1-5, pool-1-thread-3, Finalizer, Reference Handler]
6/2: 25: [pool-1-thread-5, grpc-default-executor-5, grpc-default-executor-2, grpc-default-worker-ELG-1-4, pool-4-thread-2, pool-4-thread-4, Monitor Ctrl-Break, grpc-default-executor-1, main, pool-4-thread-3, pool-1-thread-4, grpc-default-executor-4, pool-4-thread-5, grpc-default-executor-3, pool-4-thread-1, pool-1-thread-1, grpc-default-worker-ELG-1-1, grpc-default-worker-ELG-1-3, pool-1-thread-2, Attach Listener, Signal Dispatcher, pool-12-thread-1, grpc-default-worker-ELG-1-2, grpc-default-worker-ELG-1-6, grpc-default-executor-0, grpc-default-worker-ELG-1-5, pool-1-thread-3, Finalizer, Reference Handler]
6/3: 25: [pool-1-thread-5, grpc-default-executor-5, grpc-default-executor-2, grpc-default-worker-ELG-1-4, pool-4-thread-2, pool-4-thread-4, Monitor Ctrl-Break, grpc-default-executor-1, main, pool-4-thread-3, pool-1-thread-4, grpc-default-executor-4, pool-4-thread-5, grpc-default-executor-3, pool-4-thread-1, pool-1-thread-1, grpc-default-worker-ELG-1-1, grpc-default-worker-ELG-1-3, pool-1-thread-2, Attach Listener, Signal Dispatcher, grpc-default-worker-ELG-1-2, grpc-default-worker-ELG-1-6, grpc-default-executor-0, grpc-default-worker-ELG-1-5, pool-1-thread-3, Finalizer, Reference Handler]
6/4: 24: [Thread[pool-1-thread-5,5,main]=[Ljava.lang.StackTraceElement;@6c0d9d86, Thread[grpc-default-executor-5,5,main]=[Ljava.lang.StackTraceElement;@4ce1d6d0, Thread[grpc-default-executor-2,5,main]=[Ljava.lang.StackTraceElement;@24111ef1, Thread[grpc-default-worker-ELG-1-4,5,main]=[Ljava.lang.StackTraceElement;@1f3f02ee, Thread[pool-4-thread-2,5,main]=[Ljava.lang.StackTraceElement;@1fde5d22, Thread[pool-4-thread-4,5,main]=[Ljava.lang.StackTraceElement;@5dcb4f5f, Thread[Monitor Ctrl-Break,5,main]=[Ljava.lang.StackTraceElement;@71812481, Thread[grpc-default-executor-1,5,main]=[Ljava.lang.StackTraceElement;@16ce702d, Thread[main,5,main]=[Ljava.lang.StackTraceElement;@7b94089b, Thread[pool-4-thread-3,5,main]=[Ljava.lang.StackTraceElement;@7ca20101, Thread[pool-1-thread-4,5,main]=[Ljava.lang.StackTraceElement;@47f9738, Thread[grpc-default-executor-4,5,main]=[Ljava.lang.StackTraceElement;@6155d082, Thread[pool-4-thread-5,5,main]=[Ljava.lang.StackTraceElement;@3a5ecce3, Thread[grpc-default-executor-3,5,main]=[Ljava.lang.StackTraceElement;@561868a0, Thread[pool-4-thread-1,5,main]=[Ljava.lang.StackTraceElement;@2ea6e30c, Thread[pool-1-thread-1,5,main]=[Ljava.lang.StackTraceElement;@6138e79a, Thread[grpc-default-worker-ELG-1-1,5,main]=[Ljava.lang.StackTraceElement;@2dcd168a, Thread[grpc-default-worker-ELG-1-3,5,main]=[Ljava.lang.StackTraceElement;@388526fb, Thread[pool-1-thread-2,5,main]=[Ljava.lang.StackTraceElement;@21a21c64, Thread[Attach Listener,9,system]=[Ljava.lang.StackTraceElement;@7803bfd, Thread[Signal Dispatcher,9,system]=[Ljava.lang.StackTraceElement;@42bc14c1, Thread[grpc-default-worker-ELG-1-2,5,main]=[Ljava.lang.StackTraceElement;@531f4093, Thread[grpc-default-worker-ELG-1-6,5,main]=[Ljava.lang.StackTraceElement;@62ef27a8, Thread[grpc-default-executor-0,5,main]=[Ljava.lang.StackTraceElement;@6436a7db, Thread[grpc-default-worker-ELG-1-5,5,main]=[Ljava.lang.StackTraceElement;@460ebd80, Thread[pool-1-thread-3,5,main]=[Ljava.lang.StackTraceElement;@6f3c660a, Thread[Finalizer,8,system]=[Ljava.lang.StackTraceElement;@74f5ce22, Thread[Reference Handler,10,system]=[Ljava.lang.StackTraceElement;@25aca718]
7/1: 27: [pool-1-thread-5, grpc-default-executor-5, grpc-default-executor-2, grpc-default-worker-ELG-1-4, pool-4-thread-2, grpc-default-worker-ELG-1-7, pool-4-thread-4, Monitor Ctrl-Break, grpc-default-executor-1, main, pool-4-thread-3, pool-1-thread-4, grpc-default-executor-4, pool-4-thread-5, grpc-default-executor-3, pool-4-thread-1, pool-1-thread-1, grpc-default-worker-ELG-1-1, grpc-default-worker-ELG-1-3, pool-1-thread-2, Attach Listener, pool-14-thread-1, Signal Dispatcher, grpc-default-worker-ELG-1-2, grpc-default-worker-ELG-1-6, grpc-default-executor-0, grpc-default-worker-ELG-1-5, pool-1-thread-3, Finalizer, Reference Handler, grpc-default-executor-6]
7/2: 27: [pool-1-thread-5, grpc-default-executor-5, grpc-default-executor-2, grpc-default-worker-ELG-1-4, pool-4-thread-2, grpc-default-worker-ELG-1-7, pool-4-thread-4, Monitor Ctrl-Break, grpc-default-executor-1, main, pool-4-thread-3, pool-1-thread-4, grpc-default-executor-4, pool-4-thread-5, grpc-default-executor-3, pool-4-thread-1, pool-1-thread-1, grpc-default-worker-ELG-1-1, grpc-default-worker-ELG-1-3, pool-1-thread-2, Attach Listener, pool-14-thread-1, Signal Dispatcher, grpc-default-worker-ELG-1-2, grpc-default-worker-ELG-1-6, grpc-default-executor-0, grpc-default-worker-ELG-1-5, pool-1-thread-3, Finalizer, Reference Handler, grpc-default-executor-6]
7/3: 27: [pool-1-thread-5, grpc-default-executor-5, grpc-default-executor-2, grpc-default-worker-ELG-1-4, pool-4-thread-2, grpc-default-worker-ELG-1-7, pool-4-thread-4, Monitor Ctrl-Break, grpc-default-executor-1, main, pool-4-thread-3, pool-1-thread-4, grpc-default-executor-4, pool-4-thread-5, grpc-default-executor-3, pool-4-thread-1, pool-1-thread-1, grpc-default-worker-ELG-1-1, grpc-default-worker-ELG-1-3, pool-1-thread-2, Attach Listener, Signal Dispatcher, grpc-default-worker-ELG-1-2, grpc-default-worker-ELG-1-6, grpc-default-executor-0, grpc-default-worker-ELG-1-5, pool-1-thread-3, Finalizer, Reference Handler, grpc-default-executor-6]
7/4: 26: [Thread[pool-1-thread-5,5,main]=[Ljava.lang.StackTraceElement;@2a448449, Thread[grpc-default-executor-5,5,main]=[Ljava.lang.StackTraceElement;@32f232a5, Thread[grpc-default-executor-2,5,main]=[Ljava.lang.StackTraceElement;@43f82e78, Thread[grpc-default-worker-ELG-1-4,5,main]=[Ljava.lang.StackTraceElement;@e54303, Thread[pool-4-thread-2,5,main]=[Ljava.lang.StackTraceElement;@e8df99a, Thread[grpc-default-worker-ELG-1-7,5,main]=[Ljava.lang.StackTraceElement;@2dc995f4, Thread[pool-4-thread-4,5,main]=[Ljava.lang.StackTraceElement;@2f40e5db, Thread[Monitor Ctrl-Break,5,main]=[Ljava.lang.StackTraceElement;@517566b, Thread[grpc-default-executor-1,5,main]=[Ljava.lang.StackTraceElement;@64b73e7a, Thread[main,5,main]=[Ljava.lang.StackTraceElement;@530712d, Thread[pool-4-thread-3,5,main]=[Ljava.lang.StackTraceElement;@2df6226d, Thread[pool-1-thread-4,5,main]=[Ljava.lang.StackTraceElement;@12ed9db6, Thread[grpc-default-executor-4,5,main]=[Ljava.lang.StackTraceElement;@4ff4357f, Thread[pool-4-thread-5,5,main]=[Ljava.lang.StackTraceElement;@49cb9cb5, Thread[grpc-default-executor-3,5,main]=[Ljava.lang.StackTraceElement;@55322aab, Thread[pool-4-thread-1,5,main]=[Ljava.lang.StackTraceElement;@2b4c1d96, Thread[pool-1-thread-1,5,main]=[Ljava.lang.StackTraceElement;@45fd9a4d, Thread[grpc-default-worker-ELG-1-1,5,main]=[Ljava.lang.StackTraceElement;@50468873, Thread[grpc-default-worker-ELG-1-3,5,main]=[Ljava.lang.StackTraceElement;@146587a2, Thread[pool-1-thread-2,5,main]=[Ljava.lang.StackTraceElement;@5f0e9815, Thread[Attach Listener,9,system]=[Ljava.lang.StackTraceElement;@76884e4b, Thread[Signal Dispatcher,9,system]=[Ljava.lang.StackTraceElement;@126945f9, Thread[grpc-default-worker-ELG-1-2,5,main]=[Ljava.lang.StackTraceElement;@2a898881, Thread[grpc-default-worker-ELG-1-6,5,main]=[Ljava.lang.StackTraceElement;@16c63f5, Thread[grpc-default-executor-0,5,main]=[Ljava.lang.StackTraceElement;@35229f85, Thread[grpc-default-worker-ELG-1-5,5,main]=[Ljava.lang.StackTraceElement;@6d3c5255, Thread[pool-1-thread-3,5,main]=[Ljava.lang.StackTraceElement;@b1712f3, Thread[Finalizer,8,system]=[Ljava.lang.StackTraceElement;@6986bbaf, Thread[Reference Handler,10,system]=[Ljava.lang.StackTraceElement;@4879dfad, Thread[grpc-default-executor-6,5,main]=[Ljava.lang.StackTraceElement;@4758820d]
8/1: 29: [pool-1-thread-5, grpc-default-executor-5, grpc-default-executor-2, grpc-default-worker-ELG-1-4, pool-4-thread-2, grpc-default-worker-ELG-1-7, pool-4-thread-4, Monitor Ctrl-Break, grpc-default-executor-1, main, pool-4-thread-3, pool-16-thread-1, grpc-default-worker-ELG-1-8, pool-1-thread-4, grpc-default-executor-4, pool-4-thread-5, grpc-default-executor-3, pool-4-thread-1, pool-1-thread-1, grpc-default-worker-ELG-1-1, grpc-default-worker-ELG-1-3, pool-1-thread-2, Attach Listener, Signal Dispatcher, grpc-default-worker-ELG-1-2, grpc-default-worker-ELG-1-6, grpc-default-executor-0, grpc-default-worker-ELG-1-5, pool-1-thread-3, Finalizer, Reference Handler, grpc-default-executor-7, grpc-default-executor-6]
8/2: 29: [pool-1-thread-5, grpc-default-executor-5, grpc-default-executor-2, grpc-default-worker-ELG-1-4, pool-4-thread-2, grpc-default-worker-ELG-1-7, pool-4-thread-4, Monitor Ctrl-Break, grpc-default-executor-1, main, pool-4-thread-3, pool-16-thread-1, grpc-default-worker-ELG-1-8, pool-1-thread-4, grpc-default-executor-4, pool-4-thread-5, grpc-default-executor-3, pool-4-thread-1, pool-1-thread-1, grpc-default-worker-ELG-1-1, grpc-default-worker-ELG-1-3, pool-1-thread-2, Attach Listener, Signal Dispatcher, grpc-default-worker-ELG-1-2, grpc-default-worker-ELG-1-6, grpc-default-executor-0, grpc-default-worker-ELG-1-5, pool-1-thread-3, Finalizer, Reference Handler, grpc-default-executor-7, grpc-default-executor-6]
8/3: 29: [pool-1-thread-5, grpc-default-executor-5, grpc-default-executor-2, grpc-default-worker-ELG-1-4, pool-4-thread-2, grpc-default-worker-ELG-1-7, pool-4-thread-4, Monitor Ctrl-Break, grpc-default-executor-1, main, pool-4-thread-3, grpc-default-worker-ELG-1-8, pool-1-thread-4, grpc-default-executor-4, pool-4-thread-5, grpc-default-executor-3, pool-4-thread-1, pool-1-thread-1, grpc-default-worker-ELG-1-1, grpc-default-worker-ELG-1-3, pool-1-thread-2, Attach Listener, Signal Dispatcher, grpc-default-worker-ELG-1-2, grpc-default-worker-ELG-1-6, grpc-default-executor-0, grpc-default-worker-ELG-1-5, pool-1-thread-3, Finalizer, Reference Handler, grpc-default-executor-7, grpc-default-executor-6]
8/4: 28: [Thread[pool-1-thread-5,5,main]=[Ljava.lang.StackTraceElement;@1e8ce150, Thread[grpc-default-executor-5,5,main]=[Ljava.lang.StackTraceElement;@604f2bd2, Thread[grpc-default-executor-2,5,main]=[Ljava.lang.StackTraceElement;@1d3a

Stack trace

"pool-20-thread-6" googleapis/google-cloud-java#139 prio=5 os_prio=0 tid=0x00007f33ed9f1000 nid=0x184 waiting on condition [0x00007f33a9556000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000007b6a0c940> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1088)
	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

"grpc-default-executor-4" googleapis/google-cloud-java#128 daemon prio=5 os_prio=0 tid=0x00007f33d816e000 nid=0x158 waiting on condition [0x00007f33aa968000]
   java.lang.Thread.State: TIMED_WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x0000000726f346b0> (a java.util.concurrent.SynchronousQueue$TransferStack)
	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

"Gax-18" googleapis/google-cloud-java#95 daemon prio=5 os_prio=0 tid=0x00007f33b403f800 nid=0x84 waiting on condition [0x00007f33aaa69000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000007bb5e2f30> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1081)
	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

PubSub documentation used

Related issues

Metadata

Metadata

Assignees

Labels

🚨This issue needs some love.api: pubsubIssues related to the googleapis/java-pubsub API.priority: p2Moderately-important priority. Fix may not be included in next release.type: bugError or flaw in code with unintended results or allowing sub-optimal usage patterns.

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions