Error sending metrics to Stackdriver: NO_ERROR Received Goaway max_age

[pedro-carneiro]

Hello!

I ran into an issue running a Spring Boot application, using micrometer version 1.5.5, in which it logged a failed to send metrics to Stackdriver message. The full stacktrace is the following:

com.google.api.gax.rpc.UnavailableException: io.grpc.StatusRuntimeException: UNAVAILABLE: HTTP/2 error code: NO_ERROR
Received Goaway
max_age
	at com.google.api.gax.rpc.ApiExceptionFactory.createException(ApiExceptionFactory.java:69)
	at com.google.api.gax.grpc.GrpcApiExceptionFactory.create(GrpcApiExceptionFactory.java:72)
	at com.google.api.gax.grpc.GrpcApiExceptionFactory.create(GrpcApiExceptionFactory.java:60)
	at com.google.api.gax.grpc.GrpcExceptionCallable$ExceptionTransformingFuture.onFailure(GrpcExceptionCallable.java:97)
	at com.google.api.core.ApiFutures$1.onFailure(ApiFutures.java:68)
	at com.google.common.util.concurrent.Futures$CallbackListener.run(Futures.java:1056)
	at com.google.common.util.concurrent.DirectExecutor.execute(DirectExecutor.java:30)
	at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:1138)
	at com.google.common.util.concurrent.AbstractFuture.complete(AbstractFuture.java:958)
	at com.google.common.util.concurrent.AbstractFuture.setException(AbstractFuture.java:748)
	at io.grpc.stub.ClientCalls$GrpcFuture.setException(ClientCalls.java:507)
	at io.grpc.stub.ClientCalls$UnaryStreamToFuture.onClose(ClientCalls.java:482)
	at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
	at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
	at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
	at io.grpc.internal.CensusStatsModule$StatsClientInterceptor$1$1.onClose(CensusStatsModule.java:694)
	at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
	at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
	at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
	at io.grpc.internal.CensusTracingModule$TracingClientInterceptor$1$1.onClose(CensusTracingModule.java:397)
	at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:459)
	at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:63)
	at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close(ClientCallImpl.java:546)
	at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$600(ClientCallImpl.java:467)
	at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:584)
	at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
	at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:834)
	Suppressed: com.google.api.gax.rpc.AsyncTaskException: Asynchronous task failed
		at com.google.api.gax.rpc.ApiExceptions.callAndTranslateApiException(ApiExceptions.java:57)
		at com.google.api.gax.rpc.UnaryCallable.call(UnaryCallable.java:112)
		at com.google.cloud.monitoring.v3.MetricServiceClient.createTimeSeries(MetricServiceClient.java:1155)
		at io.micrometer.stackdriver.StackdriverMeterRegistry.publish(StackdriverMeterRegistry.java:169)
		at io.micrometer.core.instrument.push.PushMeterRegistry.publishSafely(PushMeterRegistry.java:52)
		at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
		at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
		at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
		... 3 more
Caused by: io.grpc.StatusRuntimeException: UNAVAILABLE: HTTP/2 error code: NO_ERROR
Received Goaway
max_age
	at io.grpc.Status.asRuntimeException(Status.java:530)
	... 22 more

[shakuzen]

We're using the google-cloud-monitoring library to send metrics. The error looks similar to one encountered over in the open-census project census-instrumentation/opencensus-java#869. It's not clear what, if anything, resolved the issue there or if it still persists. It seems like it should be a transient error though and the subsequent metric publish should be successful. We could add handling for this type of thing, but if it is a known transient error, I would expect Google's google-cloud-monitoring library to do that handling.

Could you confirm that this happens after running an application for some time, happens once, and then metrics continue to publish successfully afterwards?

[pedro-carneiro]

Fair enough.

This indeed happens after running an application for some time, but happens more or less once every hour.

[shakuzen]

happens more or less once every hour.

That would line up with the theory that the long-lived RPC connection is reaching its max life of 1 hour and being disconnected as mentioned in census-instrumentation/opencensus-java#869 (comment). I think the google-cloud-monitoring library should be handling this, ideally. I have opened https://github.com/googleapis/java-monitoring/issues/284 to see if this can be improved there.

[shakuzen]

I'm going to close this issue for now, deferring to the linked issue in the google-cloud-monitoring library. We can reopen this issue if there is action to take in Micrometer.