Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Incompatibility with java-logging-logback #1958

Open
augi opened this issue Mar 18, 2024 · 3 comments
Open

Incompatibility with java-logging-logback #1958

augi opened this issue Mar 18, 2024 · 3 comments
Assignees
Labels
api: pubsub Issues related to the googleapis/java-pubsub API. priority: p3 Desirable enhancement or fix. May not be included in next release.

Comments

@augi
Copy link

augi commented Mar 18, 2024

Environment details

  1. PubSub Java client seems to be incompatible with java-logging-logback.
  2. OS type and version: Windows, Linux
  3. Java version: 17
  4. version(s): 1.127.2, and v0.131.3-alpha

Steps to reproduce

Use both dependencies in one project.

Code example

implementation 'com.google.cloud:google-cloud-pubsub:1.127.2'
implementation 'com.google.cloud:google-cloud-logging-logback:0.131.3-alpha'
    <statusListener class="ch.qos.logback.core.status.OnConsoleStatusListener" />
    <appender name="GcpLoggingAppender" class="com.google.cloud.logging.logback.LoggingAppender">
        <redirectToStdout>true</redirectToStdout>
    </appender>
    <root level="INFO">
        <appender-ref ref="GcpLoggingAppender" />
    </root>
Publisher.newBuilder(TopicName.of("my-project", "mytopic")).build()

Stack trace

java.lang.NoClassDefFoundError: Could not initialize class io.grpc.netty.shaded.io.grpc.netty.NettyChannelBuilder
	at io.grpc.netty.shaded.io.grpc.netty.NettyChannelProvider.builderForAddress(NettyChannelProvider.java:40)
	at io.grpc.netty.shaded.io.grpc.netty.NettyChannelProvider.builderForAddress(NettyChannelProvider.java:26)
	at io.grpc.ManagedChannelBuilder.forAddress(ManagedChannelBuilder.java:44)
	at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.createSingleChannel(InstantiatingGrpcChannelProvider.java:404)
	at com.google.api.gax.grpc.ChannelPool.<init>(ChannelPool.java:107)
	at com.google.api.gax.grpc.ChannelPool.create(ChannelPool.java:85)
	at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.createChannel(InstantiatingGrpcChannelProvider.java:243)
	at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.getTransportChannel(InstantiatingGrpcChannelProvider.java:237)
	at com.google.api.gax.rpc.ClientContext.create(ClientContext.java:226)
	at com.google.cloud.pubsub.v1.stub.GrpcPublisherStub.create(GrpcPublisherStub.java:203)
	at com.google.cloud.pubsub.v1.Publisher.<init>(Publisher.java:202)
	at com.google.cloud.pubsub.v1.Publisher.<init>(Publisher.java:91)
	at com.google.cloud.pubsub.v1.Publisher$Builder.build(Publisher.java:889)
	at com.myproject.cloudsqltobigqueryshovel.Server$.$anonfun$run$1(Server.scala:31)
	at monix.eval.internal.TaskRunLoop$.startFull(TaskRunLoop.scala:88)
	at monix.eval.Task$.unsafeStartNow(Task.scala:4798)
	at monix.eval.internal.TaskBracket$BaseStart.apply(TaskBracket.scala:181)
	at monix.eval.internal.TaskBracket$BaseStart.apply(TaskBracket.scala:168)
	at monix.eval.internal.TaskRestartCallback.run(TaskRestartCallback.scala:65)
	at monix.execution.internal.Trampoline.monix$execution$internal$Trampoline$$immediateLoop(Trampoline.scala:66)
	at monix.execution.internal.Trampoline.startLoop(Trampoline.scala:32)
	at monix.execution.schedulers.TrampolineExecutionContext$JVMNormalTrampoline.super$startLoop(TrampolineExecutionContext.scala:142)
	at monix.execution.schedulers.TrampolineExecutionContext$JVMNormalTrampoline.$anonfun$startLoop$1(TrampolineExecutionContext.scala:142)
	at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.scala:18)
	at scala.concurrent.BlockContext$.withBlockContext(BlockContext.scala:94)
	at monix.execution.schedulers.TrampolineExecutionContext$JVMNormalTrampoline.startLoop(TrampolineExecutionContext.scala:142)
	at monix.execution.internal.Trampoline.execute(Trampoline.scala:40)
	at monix.execution.schedulers.TrampolineExecutionContext.execute(TrampolineExecutionContext.scala:57)
	at monix.execution.schedulers.BatchingScheduler.execute(BatchingScheduler.scala:50)
	at monix.execution.schedulers.BatchingScheduler.execute$(BatchingScheduler.scala:47)
	at monix.execution.schedulers.AsyncScheduler.execute(AsyncScheduler.scala:31)
	at monix.eval.internal.TaskRestartCallback.start(TaskRestartCallback.scala:56)
	at monix.eval.internal.TaskRunLoop$.executeAsyncTask(TaskRunLoop.scala:703)
	at monix.eval.internal.TaskRunLoop$.goAsyncForLightCB(TaskRunLoop.scala:731)
	at monix.eval.internal.TaskRunLoop$.startLight(TaskRunLoop.scala:366)
	at monix.eval.Task.runAsyncOptF(Task.scala:812)
	at monix.eval.internal.TaskEffect$.execute(TaskEffect.scala:58)
	at monix.eval.internal.TaskEffect$.$anonfun$runCancelable$1(TaskEffect.scala:51)
	at cats.effect.internals.IORunLoop$.step(IORunLoop.scala:254)
	at cats.effect.IO.unsafeRunTimed(IO.scala:338)
	at cats.effect.IO.unsafeRunSync(IO.scala:256)
	at cats.effect.SyncIO.unsafeRunSync(SyncIO.scala:51)
	at monix.eval.internal.TaskConversions$.$anonfun$toIO$1(TaskConversions.scala:42)
	at cats.effect.IO$.liftedTree1$1(IO.scala:1377)
	at cats.effect.IO$.$anonfun$cancelable$1(IO.scala:1377)
	at cats.effect.IO$.$anonfun$cancelable$1$adapted(IO.scala:1368)
	at cats.effect.internals.IOAsync$.$anonfun$apply$1(IOAsync.scala:37)
	at cats.effect.internals.IOAsync$.$anonfun$apply$1$adapted(IOAsync.scala:37)
	at cats.effect.internals.IORunLoop$RestartCallback.start(IORunLoop.scala:464)
	at cats.effect.internals.IORunLoop$.cats$effect$internals$IORunLoop$$loop(IORunLoop.scala:165)
	at cats.effect.internals.IORunLoop$RestartCallback.signal(IORunLoop.scala:480)
	at cats.effect.internals.IORunLoop$RestartCallback.apply(IORunLoop.scala:501)
	at cats.effect.internals.IORunLoop$RestartCallback.apply(IORunLoop.scala:439)
	at cats.effect.internals.Callback$AsyncIdempotentCallback.run(Callback.scala:131)
	at cats.effect.internals.Trampoline.cats$effect$internals$Trampoline$$immediateLoop(Trampoline.scala:67)
	at cats.effect.internals.Trampoline.startLoop(Trampoline.scala:35)
	at cats.effect.internals.TrampolineEC$JVMTrampoline.super$startLoop(TrampolineEC.scala:90)
	at cats.effect.internals.TrampolineEC$JVMTrampoline.$anonfun$startLoop$1(TrampolineEC.scala:90)
	at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.scala:18)
	at scala.concurrent.BlockContext$.withBlockContext(BlockContext.scala:94)
	at cats.effect.internals.TrampolineEC$JVMTrampoline.startLoop(TrampolineEC.scala:90)
	at cats.effect.internals.Trampoline.execute(Trampoline.scala:43)
	at cats.effect.internals.TrampolineEC.execute(TrampolineEC.scala:42)
	at cats.effect.internals.Callback$AsyncIdempotentCallback.apply(Callback.scala:137)
	at cats.effect.internals.Callback$AsyncIdempotentCallback.apply(Callback.scala:126)
	at cats.effect.Async$$anon$1.run(Async.scala:273)
	at java.base/java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec(ForkJoinTask.java:1395)
	at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:373)
	at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1182)
	at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1655)
	at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1622)
	at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:165)
Caused by: java.lang.ExceptionInInitializerError: Exception java.lang.NullPointerException: clazz [in thread "scala-execution-context-global-15"]
	at io.grpc.netty.shaded.io.netty.util.internal.ObjectUtil.checkNotNull(ObjectUtil.java:39)
	at io.grpc.netty.shaded.io.netty.channel.ReflectiveChannelFactory.<init>(ReflectiveChannelFactory.java:32)
	at io.grpc.netty.shaded.io.grpc.netty.NettyChannelBuilder.<clinit>(NettyChannelBuilder.java:85)
	at io.grpc.netty.shaded.io.grpc.netty.NettyChannelProvider.builderForAddress(NettyChannelProvider.java:40)
Caused by: java.lang.ExceptionInInitializerError: Exception java.lang.NullPointerException: clazz [in thread "scala-execution-context-global-15"]

	at io.grpc.netty.shaded.io.grpc.netty.NettyChannelProvider.builderForAddress(NettyChannelProvider.java:26)
	at io.grpc.ManagedChannelBuilder.forAddress(ManagedChannelBuilder.java:44)
	at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.createSingleChannel(InstantiatingGrpcChannelProvider.java:404)
	at com.google.api.gax.grpc.ChannelPool.<init>(ChannelPool.java:107)
	at com.google.api.gax.grpc.ChannelPool.create(ChannelPool.java:85)
	at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.createChannel(InstantiatingGrpcChannelProvider.java:243)
	at com.google.api.gax.grpc.InstantiatingGrpcChannelProvider.getTransportChannel(InstantiatingGrpcChannelProvider.java:237)
	at com.google.api.gax.rpc.ClientContext.create(ClientContext.java:226)
	at com.google.api.gax.rpc.ClientContext.create(ClientContext.java:149)
	at com.google.cloud.logging.spi.v2.GrpcLoggingRpc.<init>(GrpcLoggingRpc.java:150)
	at com.google.cloud.logging.LoggingOptions$DefaultLoggingRpcFactory.create(LoggingOptions.java:66)
	at com.google.cloud.logging.LoggingOptions$DefaultLoggingRpcFactory.create(LoggingOptions.java:60)
	at com.google.cloud.ServiceOptions.getRpc(ServiceOptions.java:602)
	at com.google.cloud.logging.LoggingOptions.getLoggingRpcV2(LoggingOptions.java:153)
	at com.google.cloud.logging.LoggingImpl.<init>(LoggingImpl.java:130)
	at com.google.cloud.logging.LoggingOptions$DefaultLoggingFactory.create(LoggingOptions.java:51)
	at com.google.cloud.logging.LoggingOptions$DefaultLoggingFactory.create(LoggingOptions.java:46)
	at com.google.cloud.ServiceOptions.getService(ServiceOptions.java:582)
	at com.google.cloud.logging.logback.LoggingAppender.getLogging(LoggingAppender.java:424)
	at com.google.cloud.logging.logback.LoggingAppender.start(LoggingAppender.java:358)
	at ch.qos.logback.core.model.processor.AppenderModelHandler.postHandle(AppenderModelHandler.java:84)
	at ch.qos.logback.core.model.processor.DefaultProcessor.secondPhaseTraverse(DefaultProcessor.java:257)
	at ch.qos.logback.core.model.processor.DefaultProcessor.secondPhaseTraverse(DefaultProcessor.java:253)
	at ch.qos.logback.core.model.processor.DefaultProcessor.traversalLoop(DefaultProcessor.java:90)
	at ch.qos.logback.core.model.processor.DefaultProcessor.process(DefaultProcessor.java:106)
	at ch.qos.logback.core.joran.GenericXMLConfigurator.processModel(GenericXMLConfigurator.java:208)
	at ch.qos.logback.core.joran.GenericXMLConfigurator.doConfigure(GenericXMLConfigurator.java:170)
	at ch.qos.logback.core.joran.GenericXMLConfigurator.doConfigure(GenericXMLConfigurator.java:122)
	at ch.qos.logback.core.joran.GenericXMLConfigurator.doConfigure(GenericXMLConfigurator.java:65)
	at ch.qos.logback.classic.util.DefaultJoranConfigurator.configureByResource(DefaultJoranConfigurator.java:68)
	at ch.qos.logback.classic.util.DefaultJoranConfigurator.configure(DefaultJoranConfigurator.java:35)
	at ch.qos.logback.classic.util.ContextInitializer.invokeConfigure(ContextInitializer.java:128)
	at ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:103)
	at ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:66)
	at ch.qos.logback.classic.spi.LogbackServiceProvider.initializeLoggerContext(LogbackServiceProvider.java:52)
	at ch.qos.logback.classic.spi.LogbackServiceProvider.initialize(LogbackServiceProvider.java:41)
	at org.slf4j.LoggerFactory.bind(LoggerFactory.java:196)
	at org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:183)
	at org.slf4j.LoggerFactory.getProvider(LoggerFactory.java:486)
	at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:472)
	at io.grpc.netty.shaded.io.netty.util.internal.logging.Slf4JLoggerFactory.<init>(Slf4JLoggerFactory.java:42)
	at io.grpc.netty.shaded.io.netty.util.internal.logging.Slf4JLoggerFactory$NopInstanceHolder.<clinit>(Slf4JLoggerFactory.java:63)
	at io.grpc.netty.shaded.io.netty.util.internal.logging.Slf4JLoggerFactory.getInstanceWithNopCheck(Slf4JLoggerFactory.java:59)
	at io.grpc.netty.shaded.io.netty.util.internal.logging.InternalLoggerFactory.useSlf4JLoggerFactory(InternalLoggerFactory.java:62)
	at io.grpc.netty.shaded.io.netty.util.internal.logging.InternalLoggerFactory.newDefaultFactory(InternalLoggerFactory.java:42)
	at io.grpc.netty.shaded.io.netty.util.internal.logging.InternalLoggerFactory.getDefaultFactory(InternalLoggerFactory.java:111)
	at io.grpc.netty.shaded.io.netty.util.internal.logging.InternalLoggerFactory.getInstance(InternalLoggerFactory.java:134)
	at io.grpc.netty.shaded.io.netty.util.internal.logging.InternalLoggerFactory.getInstance(InternalLoggerFactory.java:127)
	at io.grpc.netty.shaded.io.netty.util.internal.PlatformDependent.<clinit>(PlatformDependent.java:81)
	at io.grpc.netty.shaded.io.netty.util.AsciiString.<init>(AsciiString.java:225)
	at io.grpc.netty.shaded.io.netty.util.AsciiString.<init>(AsciiString.java:212)
	at io.grpc.netty.shaded.io.netty.util.AsciiString.cached(AsciiString.java:1403)
	at io.grpc.netty.shaded.io.netty.util.AsciiString.<clinit>(AsciiString.java:48)
	at io.grpc.netty.shaded.io.grpc.netty.Utils.<clinit>(Utils.java:80)
	at io.grpc.netty.shaded.io.grpc.netty.UdsNettyChannelProvider.isAvailable(UdsNettyChannelProvider.java:35)
	at io.grpc.ManagedChannelRegistry$ManagedChannelPriorityAccessor.isAvailable(ManagedChannelRegistry.java:211)
	at io.grpc.ManagedChannelRegistry$ManagedChannelPriorityAccessor.isAvailable(ManagedChannelRegistry.java:207)
	at io.grpc.ServiceProviders.loadAll(ServiceProviders.java:68)
	at io.grpc.ManagedChannelRegistry.getDefaultRegistry(ManagedChannelRegistry.java:101)
	at io.grpc.ManagedChannelProvider.provider(ManagedChannelProvider.java:43)
	... 70 more

External references such as API reference guides

Any additional information below

I checked that both dependencies use the same version of gRPC. There is no issue if we replace the GCP logging with plain stdout logging.

@product-auto-label product-auto-label bot added the api: pubsub Issues related to the googleapis/java-pubsub API. label Mar 18, 2024
@augi
Copy link
Author

augi commented Mar 19, 2024

Work around: Write a log message before the PubSub client is created. Looks like there is a race or chicken-egg at the startup.

@michaelpri10
Copy link
Contributor

I have been able to reproduce this and found a similar workaround that just by instantiating a logger using SLF4J, this error is not thrown. Example:

private static final Logger logger = LoggerFactory.getLogger(PublisherExample.class);

I'm not of the exact cause of the issue right now, but it seems to lie in a layer below the Pub/Sub client library. Some initial thoughts are that there is some dependency conflict, but I've been unable to find definitive evidence or a fix for that yet. WE will continue investigating, but currently using a workaround is the best option for this issue.

@nnnik
Copy link

nnnik commented Aug 5, 2024

java-logging-logback appears to cause similar issues with the Firestore API.
The aforementioned workaround applies.

@michaelpri10 michaelpri10 added the priority: p3 Desirable enhancement or fix. May not be included in next release. label Sep 18, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
api: pubsub Issues related to the googleapis/java-pubsub API. priority: p3 Desirable enhancement or fix. May not be included in next release.
Projects
None yet
Development

No branches or pull requests

3 participants