RuntimeException stops pushing of logs to StackDriver while logging!! about java-logging

[pmakani]

@arjun-chimbu can you provide a sample code which you have used and more details about which client version ?

[volodymyrd]

I've experienced the same issue, suppose that related that google server stop to response:
2019-10-16 15:17:23.139 CEST
Got more than one input Future failure. Logging failures after the first com.google.cloud.logging.LoggingException: io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED: deadline exceeded after 49999837376ns. [remote_addr=logging.googleapis.com/216.58.207.74:443] at com.google.cloud.logging.spi.v2.GrpcLoggingRpc$2.apply(GrpcLoggingRpc.java:191) at com.google.cloud.logging.spi.v2.GrpcLoggingRpc$2.apply(GrpcLoggingRpc.java:185) at com.google.api.core.ApiFutures$GaxFunctionToGuavaFunction.apply(ApiFutures.java:204) at com.google.common.util.concurrent.AbstractCatchingFuture$CatchingFuture.doFallback(AbstractCatchingFuture.java:206) at com.google.common.util.concurrent.AbstractCatchingFuture$CatchingFuture.doFallback(AbstractCatchingFuture.java:194) at com.google.common.util.concurrent.AbstractCatchingFuture.run(AbstractCatchingFuture.java:107) at com.google.common.util.concurrent.DirectExecutor.execute(DirectExecutor.java:30) at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:1137) at com.google.common.util.concurrent.AbstractFuture.complete(AbstractFuture.java:957) at com.google.common.util.concurrent.AbstractFuture.setException(AbstractFuture.java:748) at com.google.api.core.AbstractApiFuture$InternalSettableFuture.setException(AbstractApiFuture.java:95) at com.google.api.core.AbstractApiFuture.setException(AbstractApiFuture.java:77) at com.google.api.gax.rpc.BatchedFuture.setException(BatchedFuture.java:55) at com.google.api.gax.rpc.BatchedRequestIssuer.sendResult(BatchedRequestIssuer.java:84) at com.google.api.gax.rpc.BatchExecutor$1.onFailure(BatchExecutor.java:98) at com.google.api.core.ApiFutures$1.onFailure(ApiFutures.java:68) at com.google.common.util.concurrent.Futures$CallbackListener.run(Futures.java:1015) at com.google.common.util.concurrent.DirectExecutor.execute(DirectExecutor.java:30) at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:1137) at com.google.common.util.concurrent.AbstractFuture.complete(AbstractFuture.java:957) at com.google.common.util.concurrent.AbstractFuture.setException(AbstractFuture.java:748) at com.google.api.gax.retrying.BasicRetryingFuture.handleAttempt(BasicRetryingFuture.java:179) at com.google.api.gax.retrying.CallbackChainRetryingFuture$AttemptCompletionListener.handle(CallbackChainRetryingFuture.java:135) at com.google.api.gax.retrying.CallbackChainRetryingFuture$AttemptCompletionListener.run(CallbackChainRetryingFuture.java:117) at com.google.common.util.concurrent.DirectExecutor.execute(DirectExecutor.java:30) at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:1137) at com.google.common.util.concurrent.AbstractFuture.complete(AbstractFuture.java:957) at com.google.common.util.concurrent.AbstractFuture.setException(AbstractFuture.java:748) at com.google.api.core.AbstractApiFuture$InternalSettableFuture.setException(AbstractApiFuture.java:95) at com.google.api.core.AbstractApiFuture.setException(AbstractApiFuture.java:77) 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:1015) at com.google.common.util.concurrent.DirectExecutor.execute(DirectExecutor.java:30) at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:1137) at com.google.common.util.concurrent.AbstractFuture.complete(AbstractFuture.java:957) at com.google.common.util.concurrent.AbstractFuture.setException(AbstractFuture.java:748) at io.grpc.stub.ClientCalls$GrpcFuture.setException(ClientCalls.java:515) at io.grpc.stub.ClientCalls$UnaryStreamToFuture.onClose(ClientCalls.java:490) 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:700) 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:399) at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:510) at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:66) at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close(ClientCallImpl.java:630) at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$700(ClientCallImpl.java:518) at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInternal(ClientCallImpl.java:692) at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:681) at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37) at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123) 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:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) caused by: com.google.api.gax.rpc.DeadlineExceededException: io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED: deadline exceeded after 49999837376ns. [remote_addr=logging.googleapis.com/216.58.207.74:443] at com.google.api.gax.rpc.ApiExceptionFactory.createException(ApiExceptionFactory.java:51) at com.google.api.gax.grpc.GrpcApiExceptionFactory.create(GrpcApiExceptionFactory.java:72) at com.google.api.gax.grpc.GrpcApiExceptionFactory.create(GrpcApiExceptionFactory.java:60) ... 32 common frames elided caused by: io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED: deadline exceeded after 49999837376ns. [remote_addr=logging.googleapis.com/216.58.207.74:443] at io.grpc.Status.asRuntimeException(Status.java:533) ... 24 common frames elided

The application stops working and only restart helps.

[codyoss]

@chingor13 are you looking into this?

[genyherrera]

@arjun-chimbu Relate to the fist issue,

java.lang.RuntimeException: com.google.cloud.logging.LoggingException: io.grpc.StatusRuntimeException: UNAVAILABLE: io exception

For me it was happening te same thing, and all started just after I update my application from Java 8 to Java 9. After looking like crazy on the web and not found any possible solution I decided to break down by pieces.

I create a brand new project just with google-cloud-logging-logback as dependency and I was able to reproduce the issue. Next step, I change the logback to DEBUG and that was when it told me was was my problem. I got a sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid certification path to requested target..

So for my next test, i just copy the cacerts file from /Library/Java/JavaVirtualMachines/jdk1.8.0_172.jdk/Contents/Home/jre/lib/security to /Library/Java/JavaVirtualMachines/jdk-9.0.4.jdk/Contents/Home/lib/security and them it WORKED!

I will register here this solution, so maybe if someone face this again, there is one possible solution. At least the one that worked for me.

Thanks

[codyoss]

@genyherrera thanks for sharing

[codyoss]

I am not sure there is a great solution for this. The client does do some internal retrying for writing logs.(It look like for up to 10 minutes) I don't think it is right to retry forever. Eventually if the service did not come back fast enough you would just OOM.I think the right thing to do in this situation is to restart an app once the service is available again. If this is Spring Boot I might suggest finding a way to add a health check.

[chingor13]

Closing at is seems there's nothing we can really do here.