Google-cloud-java: 502 Bad Gateway Pub/Sub 0.9.0-alpha

Created on 13 Feb 2017  路  13Comments  路  Source: googleapis/google-cloud-java

Hey, Trying out the new pubsub client and I'm getting 502 Bad Gateway. 

17:51:44.832 |- INFO  c.wemesh.clerk.GooglePubSubConsumer$ - Waiting for messages from subscription: x.events.gray
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.Subscriber$SubscriberImpl doStart
INFO: Starting subscriber group.
Feb 13, 2017 5:51:46 PM io.grpc.internal.ManagedChannelImpl <init>
INFO: [ManagedChannelImpl@1442f788] Created with target pubsub.googleapis.com:443
Feb 13, 2017 5:51:46 PM io.grpc.internal.ManagedChannelImpl <init>
INFO: [ManagedChannelImpl@42373389] Created with target pubsub.googleapis.com:443
Feb 13, 2017 5:51:46 PM io.grpc.internal.ManagedChannelImpl <init>
INFO: [ManagedChannelImpl@9b21bd3] Created with target pubsub.googleapis.com:443
Feb 13, 2017 5:51:46 PM io.grpc.internal.ManagedChannelImpl <init>
INFO: [ManagedChannelImpl@a62c7cd] Created with target pubsub.googleapis.com:443
Feb 13, 2017 5:51:46 PM io.grpc.internal.ManagedChannelImpl <init>
INFO: [ManagedChannelImpl@7661b5a] Created with target pubsub.googleapis.com:443
Feb 13, 2017 5:51:46 PM io.grpc.internal.ManagedChannelImpl <init>
INFO: [ManagedChannelImpl@7c36db44] Created with target pubsub.googleapis.com:443
Feb 13, 2017 5:51:46 PM io.grpc.internal.ManagedChannelImpl <init>
INFO: [ManagedChannelImpl@65c33b92] Created with target pubsub.googleapis.com:443
Feb 13, 2017 5:51:46 PM io.grpc.internal.ManagedChannelImpl <init>
INFO: [ManagedChannelImpl@7903d448] Created with target pubsub.googleapis.com:443
Feb 13, 2017 5:51:46 PM io.grpc.internal.ManagedChannelImpl <init>
INFO: [ManagedChannelImpl@4e08acf9] Created with target pubsub.googleapis.com:443
Feb 13, 2017 5:51:46 PM io.grpc.internal.ManagedChannelImpl <init>
INFO: [ManagedChannelImpl@42ea287] Created with target pubsub.googleapis.com:443
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection doStart
INFO: Starting subscriber.
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection doStart
INFO: Starting subscriber.
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection doStart
INFO: Starting subscriber.
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection doStart
INFO: Starting subscriber.
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection doStart
INFO: Starting subscriber.
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection doStart
INFO: Starting subscriber.
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection doStart
INFO: Starting subscriber.
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection doStart
INFO: Starting subscriber.
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection doStart
INFO: Starting subscriber.
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection doStart
INFO: Starting subscriber.
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection initialize
INFO: Initializing stream to subscription projects/wemesh-inc/subscriptions/x.events.gray with deadline 10
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection initialize
INFO: Initializing stream to subscription projects/wemesh-inc/subscriptions/x.events.gray with deadline 10
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection initialize
INFO: Initializing stream to subscription projects/wemesh-inc/subscriptions/x.events.gray with deadline 10
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection initialize
INFO: Initializing stream to subscription projects/wemesh-inc/subscriptions/x.events.gray with deadline 10
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection initialize
INFO: Initializing stream to subscription projects/wemesh-inc/subscriptions/x.events.gray with deadline 10
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection initialize
INFO: Initializing stream to subscription projects/wemesh-inc/subscriptions/x.events.gray with deadline 10
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection initialize
INFO: Initializing stream to subscription projects/wemesh-inc/subscriptions/x.events.gray with deadline 10
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection initialize
INFO: Initializing stream to subscription projects/wemesh-inc/subscriptions/x.events.gray with deadline 10
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection initialize
INFO: Initializing stream to subscription projects/wemesh-inc/subscriptions/x.events.gray with deadline 10
Feb 13, 2017 5:51:46 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection initialize
INFO: Initializing stream to subscription projects/wemesh-inc/subscriptions/x.events.gray with deadline 10
17:51:46.536 |- INFO  com.wemesh.clerk.RpcServer - Server started, listening on 10006
Feb 13, 2017 5:51:47 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection$StreamingPullResponseObserver onError
INFO: Terminated streaming with exception
io.grpc.StatusRuntimeException: UNAVAILABLE: 502:Bad Gateway
    at io.grpc.Status.asRuntimeException(Status.java:545)
    at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:395)
    at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close(ClientCallImpl.java:481)
    at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$600(ClientCallImpl.java:398)
    at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:513)
    at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:52)
    at io.grpc.internal.SerializingExecutor$TaskRunner.run(SerializingExecutor.java:154)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

Feb 13, 2017 5:51:47 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection$StreamingPullResponseObserver onError
INFO: Terminated streaming with exception
io.grpc.StatusRuntimeException: UNAVAILABLE: 502:Bad Gateway
    at io.grpc.Status.asRuntimeException(Status.java:545)
    at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:395)
    at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close(ClientCallImpl.java:481)
    at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$600(ClientCallImpl.java:398)
    at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:513)
    at io.grpc.internal.ContextRunnable.run(ContextRun
pubsub
Source
picture GEverding

Most helpful comment

It doesn't fall back properly. When the status code is UNAVAILABLE (src) it still considers the connection retryable and doesn't call notifyFailure (src) and then the failure handler in subscriber doesn't switch to polling (src)

picture GEverding on 13 Feb 2017
👍2

All 13 comments

Subscriber is designed to fall back to polling if the streaming doesn't work. Notice that all of the logs are at INFO level. Is the polling logic working?

garrettjonesgoogle picture garrettjonesgoogle on 13 Feb 2017

It doesn't fall back properly. When the status code is UNAVAILABLE (src) it still considers the connection retryable and doesn't call notifyFailure (src) and then the failure handler in subscriber doesn't switch to polling (src)

GEverding picture GEverding on 13 Feb 2017
👍2

I'm experiencing the same issue. My logs are continuous streams of "UNAVAILABLE: 502:Bad Gateway" and messages aren't being processed.

matthewrj picture matthewrj on 14 Feb 2017

Is there any workaround for this issue? I tried packaging up a custom version of the library but ran into issues with maven?

GEverding picture GEverding on 14 Feb 2017

We will get a fix out soon.

garrettjonesgoogle picture garrettjonesgoogle on 14 Feb 2017
👍1

This should be fixed by https://github.com/GoogleCloudPlatform/google-cloud-java/pull/1625 ; we'll try to get a release out soon.

garrettjonesgoogle picture garrettjonesgoogle on 15 Feb 2017

@garrettjonesgoogle The mentioned fix went out with 0.9.1. I think we can close this out?

pongad picture pongad on 18 Feb 2017

I am getting the same message in 0.9.2.

Feb 18, 2017 8:30:18 PM com.google.cloud.pubsub.spi.v1.StreamingSubscriberConnection$StreamingPullResponseObserver onError
INFO: Terminated streaming with exception
io.grpc.StatusRuntimeException: UNAVAILABLE: 502:Bad Gateway
    at io.grpc.Status.asRuntimeException(Status.java:545)
    at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:395)
    at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close(ClientCallImpl.java:481)
    at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$600(ClientCallImpl.java:398)
    at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:513)
    at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:52)
    at io.grpc.internal.SerializingExecutor$TaskRunner.run(SerializingExecutor.java:154)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

By 0.9.2, I mean the jar on maven tagged as 0.9.2-alpha

prestonvanloon picture prestonvanloon on 19 Feb 2017

I'm experiencing the same issue on 0.9.2-alpha.

masangin picture masangin on 19 Feb 2017

I must have looked at the history wrong somehow.
The fix for this landed in commit 68ce84d313b7745b1dc37be300522ea1c051063b, 3 commits after the last release. This should be fixed in the next release.
I apologize for the confusion.

pongad picture pongad on 20 Feb 2017

when can we reasonably expect this in a new release? The library is broken right now.

GEverding picture GEverding on 21 Feb 2017

The fix has been released in 0.9.3-alpha. Now closing this issue.

garrettjonesgoogle picture garrettjonesgoogle on 23 Feb 2017

Thanks @garrettjonesgoogle. 0.9.3-alpha is working well so far.

prestonvanloon picture prestonvanloon on 23 Feb 2017
Was this page helpful?
0 / 5 - 0 ratings

Related issues

kevmo314 picture kevmo314  路  21Comments
vam-google picture vam-google  路  22Comments
sparhomenko picture sparhomenko  路  21Comments
codemoped picture codemoped  路  36Comments
goxr3plus picture goxr3plus  路  28Comments