Skip to content

Spanner - Running Spanner on AppEngine SDK throws an NPE #1856

Closed
Closed
Spanner - Running Spanner on AppEngine SDK throws an NPE#1856
Assignees
vkedia
Labels
api: spannerIssues related to the Spanner API.priority: p1Important issue which blocks shipping the next release. Will be fixed prior to next release.running on app enginetype: bugError or flaw in code with unintended results or allowing sub-optimal usage patterns.
Milestone
Spanner GA

Description

@saturnism
saturnism
opened on Apr 4, 2017

https://github.com/GoogleCloudPlatform/google-cloud-java/blob/master/google-cloud-spanner/src/main/java/com/google/cloud/spanner/SessionPool.java#L987

When using Spanner library in AppEngine Standard w/ Java 8 (alpha), createSession() ultimately throws an error, but was consumed and not propagated. Debugger shows a NullPointerException was thrown. However, because it wasn't propagated, the application thread was hung while waiting to take an available session:
https://github.com/GoogleCloudPlatform/google-cloud-java/blob/master/google-cloud-spanner/src/main/java/com/google/cloud/spanner/SessionPool.java#L697

Expected behavior - if connection is unable to open, propagate the exception.

Activity

  1. vkedia
    added
    api: spannerIssues related to the Spanner API.
    on Apr 5, 2017

  2. vkedia commented on Apr 5, 2017

    @vkedia
    vkedia
    on Apr 5, 2017

    We dont expect any other exception to be thrown by createSession other than SpannerException, which is why it just catches that.
    Do you have the trace for NPE?

  3. ludoch commented on Apr 5, 2017

    @ludoch
    ludoch
    on Apr 5, 2017 via email
    Contributor

  4. ludoch commented on Apr 5, 2017

    @ludoch
    ludoch
    on Apr 5, 2017
    Contributor

    appengine-guestbook-java.zip
    contains a simple (stupid) spanner servlet with hardcoded project data...
    You can execute with mvn appengine:devserver which starts the local server in debug mode with
    -agentlib:jdwp=transport=dt_socket,address=7999,server=y,suspend=n
    so you can debug if you want....
    If you want to deploy (mvn appengine:update), change the project name and version in the pom.xml but first, you need to be whitelisted for Java8. Ask me...

  5. vkedia commented on Apr 5, 2017

    @vkedia
    vkedia
    on Apr 5, 2017

    Thanks. I will try this out. I will let you know if I need to be whitelisted.

  6. saturnism commented on Apr 8, 2017

    @saturnism
    saturnism
    on Apr 8, 2017
    Author

    the issue w/o exception is that the subsequent operations get blocked indefinitely (e.g.., getting a readcontext). It took a while to trace back to what was blocking it.

    i'm inclined to say exception should always be propagated when it wasn't working as intended.

  7. ludoch commented on Apr 13, 2017

    @ludoch
    ludoch
    on Apr 13, 2017
    Contributor

    Friendly ping.

  8. vkedia commented on Apr 20, 2017

    @vkedia
    vkedia
    on Apr 20, 2017

    Sorry I was on vacation. I will take a look at this next week.

  9. vkedia commented on Apr 20, 2017

    @vkedia
    vkedia
    on Apr 20, 2017

    @saturnism I think you are right. We should handle any Runtime exception here. I will make that change.

  10. vkedia commented on May 1, 2017

    @vkedia
    vkedia
    on May 1, 2017

    #2026 should fix the issue with exception handling.

  11. shinfan
    modified the milestone: Spanner GA on May 8, 2017

  12. vkedia commented on May 12, 2017

    @vkedia
    vkedia
    on May 12, 2017

    This should be fixed now. @ludoch Can you please try now and close this issue is it works.

  13. vam-google
    added
    type: bugError or flaw in code with unintended results or allowing sub-optimal usage patterns.
    on May 24, 2017

  14. ludoch commented on May 24, 2017

    @ludoch
    ludoch
    on May 24, 2017
    Contributor

    So I tried the attached sample above with upgrading to 1.9.53 for GAE and 0.17.2-beta for Spanner.

    After a local run, I go to the http://localhost:8080/SpannerServlet . URL and gets this error:
    May 24, 2017 2:44:17 PM com.google.appengine.api.datastore.dev.LocalDatastoreService load
    INFO: The backing store, /Users/ludo/Downloads/appengine-guestbook-javaspannerbug/target/spaneerbug-guestbook-Java8-Standard-1.0-SNAPSHOT/WEB-INF/appengine-generated/local_db.bin, does not exist. It will be created.
    May 24, 2017 2:44:22 PM io.grpc.internal.ChannelExecutor drain
    WARNING: Runnable threw exception in ChannelExecutor
    java.lang.NullPointerException
    at com.google.appengine.tools.development.RequestEndListenerHelper.getListeners(RequestEndListenerHelper.java:52)
    at com.google.appengine.tools.development.RequestEndListenerHelper.register(RequestEndListenerHelper.java:39)
    at com.google.appengine.tools.development.RequestThreadFactory$1$1.start(RequestThreadFactory.java:65)
    at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:950)
    at java.util.concurrent.ThreadPoolExecutor.ensurePrestart(ThreadPoolExecutor.java:1587)
    at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:334)
    at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:533)
    at io.grpc.internal.ManagedChannelImpl.rescheduleIdleTimer(ManagedChannelImpl.java:336)
    at io.grpc.internal.ManagedChannelImpl.exitIdleMode(ManagedChannelImpl.java:301)
    at io.grpc.internal.ManagedChannelImpl$4$1.run(ManagedChannelImpl.java:359)
    at io.grpc.internal.ChannelExecutor.drain(ChannelExecutor.java:87)
    at io.grpc.internal.ManagedChannelImpl$4.get(ManagedChannelImpl.java:361)
    at io.grpc.internal.ClientCallImpl.start(ClientCallImpl.java:221)
    at io.grpc.ForwardingClientCall.start(ForwardingClientCall.java:47)
    at com.google.cloud.spanner.spi.v1.WatchdogInterceptor$MonitoredCall.start(WatchdogInterceptor.java:194)
    at io.grpc.ForwardingClientCall.start(ForwardingClientCall.java:47)
    at com.google.cloud.spanner.spi.v1.SpannerErrorInterceptor$1.start(SpannerErrorInterceptor.java:67)
    at io.grpc.ForwardingClientCall.start(ForwardingClientCall.java:47)
    at com.google.cloud.spanner.spi.v1.GrpcSpannerRpc$MetadataClientCall.start(GrpcSpannerRpc.java:456)
    at io.grpc.stub.ClientCalls.startCall(ClientCalls.java:270)
    at io.grpc.stub.ClientCalls.asyncUnaryRequestCall(ClientCalls.java:249)
    at io.grpc.stub.ClientCalls.futureUnaryCall(ClientCalls.java:186)
    at com.google.cloud.spanner.spi.v1.GrpcSpannerRpc.doUnaryCall(GrpcSpannerRpc.java:420)
    at com.google.cloud.spanner.spi.v1.GrpcSpannerRpc.createSession(GrpcSpannerRpc.java:323)
    at com.google.cloud.spanner.SpannerImpl$2.call(SpannerImpl.java:223)
    at com.google.cloud.spanner.SpannerImpl$2.call(SpannerImpl.java:220)
    at com.google.cloud.spanner.SpannerImpl.runWithRetries(SpannerImpl.java:202)
    at com.google.cloud.spanner.SpannerImpl.createSession(SpannerImpl.java:219)
    at com.google.cloud.spanner.SessionPool$4.run(SessionPool.java:987)
    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:748)

    May 24, 2017 2:44:22 PM io.grpc.internal.ManagedChannelImpl$NameResolverListenerImpl onError
    WARNING: [io.grpc.internal.ManagedChannelImpl-1] Failed to resolve name. status=Status{code=UNKNOWN, description=null, cause=java.lang.NullPointerException
    at com.google.appengine.tools.development.RequestEndListenerHelper.getListeners(RequestEndListenerHelper.java:52)
    at com.google.appengine.tools.development.RequestEndListenerHelper.register(RequestEndListenerHelper.java:39)
    at com.google.appengine.tools.development.RequestThreadFactory$1$1.start(RequestThreadFactory.java:65)
    at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:950)
    at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1368)
    at io.grpc.internal.DnsNameResolver.resolve(DnsNameResolver.java:205)
    at io.grpc.internal.DnsNameResolver.start(DnsNameResolver.java:116)
    at io.grpc.internal.ManagedChannelImpl.exitIdleMode(ManagedChannelImpl.java:313)
    at io.grpc.internal.ManagedChannelImpl$2.handleInUse(ManagedChannelImpl.java:241)
    at io.grpc.internal.InUseStateAggregator.updateObjectInUse(InUseStateAggregator.java:55)
    at io.grpc.internal.ManagedChannelImpl$1.transportInUse(ManagedChannelImpl.java:200)
    at io.grpc.internal.DelayedClientTransport$1.run(DelayedClientTransport.java:110)
    at io.grpc.internal.ChannelExecutor.drain(ChannelExecutor.java:87)
    at io.grpc.internal.DelayedClientTransport.newStream(DelayedClientTransport.java:185)
    at io.grpc.internal.ClientCallImpl.start(ClientCallImpl.java:225)
    at io.grpc.ForwardingClientCall.start(ForwardingClientCall.java:47)
    at com.google.cloud.spanner.spi.v1.WatchdogInterceptor$MonitoredCall.start(WatchdogInterceptor.java:194)
    at io.grpc.ForwardingClientCall.start(ForwardingClientCall.java:47)
    at com.google.cloud.spanner.spi.v1.SpannerErrorInterceptor$1.start(SpannerErrorInterceptor.java:67)
    at io.grpc.ForwardingClientCall.start(ForwardingClientCall.java:47)
    at com.google.cloud.spanner.spi.v1.GrpcSpannerRpc$MetadataClientCall.start(GrpcSpannerRpc.java:456)
    at io.grpc.stub.ClientCalls.startCall(ClientCalls.java:270)
    at io.grpc.stub.ClientCalls.asyncUnaryRequestCall(ClientCalls.java:249)
    at io.grpc.stub.ClientCalls.futureUnaryCall(ClientCalls.java:186)
    at com.google.cloud.spanner.spi.v1.GrpcSpannerRpc.doUnaryCall(GrpcSpannerRpc.java:420)
    at com.google.cloud.spanner.spi.v1.GrpcSpannerRpc.createSession(GrpcSpannerRpc.java:323)
    at com.google.cloud.spanner.SpannerImpl$2.call(SpannerImpl.java:223)
    at com.google.cloud.spanner.SpannerImpl$2.call(SpannerImpl.java:220)
    at com.google.cloud.spanner.SpannerImpl.runWithRetries(SpannerImpl.java:202)
    at com.google.cloud.spanner.SpannerImpl.createSession(SpannerImpl.java:219)
    at com.google.cloud.spanner.SessionPool$4.run(SessionPool.java:987)
    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:748)
    }
    May 24, 2017 2:44:22 PM io.grpc.internal.ChannelExecutor drain
    WARNING: Runnable threw exception in ChannelExecutor
    java.lang.NullPointerException
    at com.google.appengine.tools.development.RequestEndListenerHelper.getListeners(RequestEndListenerHelper.java:52)
    at com.google.appengine.tools.development.RequestEndListenerHelper.register(RequestEndListenerHelper.java:39)
    at com.google.appengine.tools.development.RequestThreadFactory$1$1.start(RequestThreadFactory.java:65)
    at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:950)
    at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1368)
    at io.grpc.internal.DelayedClientTransport.reprocess(DelayedClientTransport.java:306)
    at io.grpc.internal.ManagedChannelImpl$LbHelperImpl$5.run(ManagedChannelImpl.java:724)
    at io.grpc.internal.ChannelExecutor.drain(ChannelExecutor.java:87)
    at io.grpc.internal.DelayedClientTransport.newStream(DelayedClientTransport.java:185)
    at io.grpc.internal.ClientCallImpl.start(ClientCallImpl.java:225)
    at io.grpc.ForwardingClientCall.start(ForwardingClientCall.java:47)
    at com.google.cloud.spanner.spi.v1.WatchdogInterceptor$MonitoredCall.start(WatchdogInterceptor.java:194)
    at io.grpc.ForwardingClientCall.start(ForwardingClientCall.java:47)
    at com.google.cloud.spanner.spi.v1.SpannerErrorInterceptor$1.start(SpannerErrorInterceptor.java:67)
    at io.grpc.ForwardingClientCall.start(ForwardingClientCall.java:47)
    at com.google.cloud.spanner.spi.v1.GrpcSpannerRpc$MetadataClientCall.start(GrpcSpannerRpc.java:456)
    at io.grpc.stub.ClientCalls.startCall(ClientCalls.java:270)
    at io.grpc.stub.ClientCalls.asyncUnaryRequestCall(ClientCalls.java:249)
    at io.grpc.stub.ClientCalls.futureUnaryCall(ClientCalls.java:186)
    at com.google.cloud.spanner.spi.v1.GrpcSpannerRpc.doUnaryCall(GrpcSpannerRpc.java:420)
    at com.google.cloud.spanner.spi.v1.GrpcSpannerRpc.createSession(GrpcSpannerRpc.java:323)
    at com.google.cloud.spanner.SpannerImpl$2.call(SpannerImpl.java:223)
    at com.google.cloud.spanner.SpannerImpl$2.call(SpannerImpl.java:220)
    at com.google.cloud.spanner.SpannerImpl.runWithRetries(SpannerImpl.java:202)
    at com.google.cloud.spanner.SpannerImpl.createSession(SpannerImpl.java:219)
    at com.google.cloud.spanner.SessionPool$4.run(SessionPool.java:987)
    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:748)

    May 24, 2017 2:44:23 PM io.grpc.internal.ChannelExecutor drain
    WARNING: Runnable threw exception in ChannelExecutor
    java.lang.NullPointerException
    at com.google.appengine.tools.development.RequestEndListenerHelper.getListeners(RequestEndListenerHelper.java:52)
    at com.google.appengine.tools.development.RequestEndListenerHelper.register(RequestEndListenerHelper.java:39)
    at com.google.appengine.tools.development.RequestThreadFactory$1$1.start(RequestThreadFactory.java:65)
    at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:950)
    at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1366)
    at io.grpc.internal.DelayedClientTransport.reprocess(DelayedClientTransport.java:306)
    at io.grpc.internal.ManagedChannelImpl$LbHelperImpl$5.run(ManagedChannelImpl.java:724)
    at io.grpc.internal.ChannelExecutor.drain(ChannelExecutor.java:87)
    at io.grpc.internal.InternalSubchannel$TransportListener.transportReady(InternalSubchannel.java:415)
    at io.grpc.netty.ClientTransportLifecycleManager.notifyReady(ClientTransportLifecycleManager.java:58)
    at io.grpc.netty.NettyClientHandler$FrameListener.onSettingsRead(NettyClientHandler.java:636)
    at io.grpc.netty.FixedHttp2ConnectionDecoder$FrameReadListener.onSettingsRead(FixedHttp2ConnectionDecoder.java:458)
    at io.grpc.netty.FixedHttp2ConnectionDecoder$PrefaceFrameListener.onSettingsRead(FixedHttp2ConnectionDecoder.java:670)
    at io.netty.handler.codec.http2.Http2InboundFrameLogger$1.onSettingsRead(Http2InboundFrameLogger.java:93)
    at io.netty.handler.codec.http2.DefaultHttp2FrameReader.readSettingsFrame(DefaultHttp2FrameReader.java:546)
    at io.netty.handler.codec.http2.DefaultHttp2FrameReader.processPayloadState(DefaultHttp2FrameReader.java:262)
    at io.netty.handler.codec.http2.DefaultHttp2FrameReader.readFrame(DefaultHttp2FrameReader.java:160)
    at io.netty.handler.codec.http2.Http2InboundFrameLogger.readFrame(Http2InboundFrameLogger.java:41)
    at io.grpc.netty.FixedHttp2ConnectionDecoder.decodeFrame(FixedHttp2ConnectionDecoder.java:119)
    at io.netty.handler.codec.http2.Http2ConnectionHandler$FrameDecoder.decode(Http2ConnectionHandler.java:341)
    at io.netty.handler.codec.http2.Http2ConnectionHandler$PrefaceDecoder.decode(Http2ConnectionHandler.java:220)
    at io.netty.handler.codec.http2.Http2ConnectionHandler.decode(Http2ConnectionHandler.java:401)
    at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:411)
    at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:248)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:349)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:341)
    at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1228)
    at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1039)
    at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:411)
    at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:248)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:349)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:341)
    at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1334)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:349)
    at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:926)
    at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:129)
    at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:642)
    at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:565)
    at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:479)
    at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:441)
    at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
    at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:144)
    at java.lang.Thread.run(Thread.java:748)

    Maybe it now a different error?

  15. 13 remaining items

  16. ludoch commented on May 25, 2017

    @ludoch
    ludoch
    on May 25, 2017
    Contributor

    Remember also the failure is on the GAE SDK.
    I did not test in prod... Someone tried?

  17. garrettjonesgoogle
    added
    priority: p1Important issue which blocks shipping the next release. Will be fixed prior to next release.
    on May 30, 2017
  18. jabubake
    added
    running on app engine
    on Aug 4, 2017
  19. garrettjonesgoogle
    assigned
    vkedia
    on Aug 10, 2017

  20. vkedia commented on Aug 22, 2017

    @vkedia
    vkedia
    on Aug 22, 2017

    I believe @jabubake Was able to get this to work on App Engine Prod. So this must be an issue on the SDK only.

  21. vkedia
    changed the title [-]Spanner - SessionPool.createSession consumed exception silently[/-] [+]Spanner - Running Spanner on AppEngine SDK throws an NPE[/+] on Aug 22, 2017

  22. ludoch commented on Sep 20, 2017

    @ludoch
    ludoch
    on Sep 20, 2017
    Contributor

    We believe it is now fix. Ray, please reopen if you still see the issue.

  23. ludoch
    closed this as completedon Sep 20, 2017
  24. meltsufin
    added a commit that references this issue on Dec 22, 2025

    chore(main): release 3.23.5-SNAPSHOT (#1856)

    bf046e5
  25. suztomo
    added a commit that references this issue on Mar 11, 2026

    chore(main): release 3.23.5-SNAPSHOT (googleapis#1856)

    b8523aa
  26. meltsufin
    added 3 commits that reference this issue on Apr 29, 2026

    build(deps): update dependency org.apache.maven.plugins:maven-surefir…

    7a32932

    build(deps): update dependency org.apache.maven.plugins:maven-surefir…

    21dc56b

    chore(main): release 3.26.6-SNAPSHOT (#1856)

    a87508c
  27. benjaminp
    added 2 commits that reference this issue on Jul 13, 2026

    feat: add last_scanned_row_key feature (googleapis#1856)

    df543d5

    chore(main): release 2.26.0 (googleapis#1859)

    3a7c1e9
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

api: spannerIssues related to the Spanner API.priority: p1Important issue which blocks shipping the next release. Will be fixed prior to next release.running on app enginetype: bugError or flaw in code with unintended results or allowing sub-optimal usage patterns.

Type

No type

Projects

No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions