ScanRetriesExhaustedException when reading from bigtable in a managed VM setup

[vc13819]

I am not able to do any bigtable operations from the managed VM setup. The bigtable operations are working fine from my local machine, but timeout on the cloud(Managed VM). The setup was working fine on managed VM as well till yesterday.

I am using version 0.2.2 of cloud-bigtable-client with hbase1.1 (also version 0.2.2).

The error I get in the log is:
Caused by: com.google.cloud.bigtable.grpc.scanner.ScanRetriesExhaustedException: Exhausted streaming retries.
at com.google.cloud.bigtable.grpc.scanner.ResumingStreamingResultScanner.backOffAndRetry(ResumingStreamingResultScanner.java:142)
at com.google.cloud.bigtable.grpc.scanner.ResumingStreamingResultScanner.next(ResumingStreamingResultScanner.java:112)
at com.google.cloud.bigtable.grpc.scanner.ResumingStreamingResultScanner.next(ResumingStreamingResultScanner.java:42)
at com.google.cloud.bigtable.hbase.adapters.BigtableResultScannerAdapter$1.next(BigtableResultScannerAdapter.java:43)
at org.apache.hadoop.hbase.client.AbstractClientScanner$1.hasNext(AbstractClientScanner.java:94)
... 11 more
Caused by: com.google.cloud.bigtable.grpc.scanner.ScanTimeoutException: Timeout while merging responses.
at com.google.cloud.bigtable.grpc.scanner.ResponseQueueReader.getNext(ResponseQueueReader.java:113)
at com.google.cloud.bigtable.grpc.scanner.ResponseQueueReader.getNextMergedRow(ResponseQueueReader.java:64)
at com.google.cloud.bigtable.grpc.scanner.StreamingBigtableResultScanner.next(StreamingBigtableResultScanner.java:64)
at com.google.cloud.bigtable.grpc.scanner.StreamingBigtableResultScanner.next(StreamingBigtableResultScanner.java:28)
at com.google.cloud.bigtable.grpc.scanner.ResumingStreamingResultScanner.next(ResumingStreamingResultScanner.java:101)
... 14 more

[vc13819]

Digging some more, This is the error I see in the logs. I get the same error if I copy a simple command line app to Google Compute engine.

Exception in thread "pool-2-thread-2" java.lang.IllegalAccessError: tried to access field sun.security.ssl.Handshak
er.localSupportedSignAlgs from class sun.security.ssl.ClientHandshaker
at sun.security.ssl.ClientHandshaker.processMessage(ClientHandshaker.java:278)
at sun.security.ssl.Handshaker.processLoop(Handshaker.java:913)
at sun.security.ssl.Handshaker.process_record(Handshaker.java:849)
at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:1035)
at sun.security.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1344)
at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1371)
at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1355)
at sun.net.www.protocol.https.HttpsClient.afterConnect(HttpsClient.java:559)
at sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.connect(AbstractDelegateHttpsURLConnection
.java:185)
at sun.net.www.protocol.http.HttpURLConnection.getOutputStream(HttpURLConnection.java:1093)
at sun.net.www.protocol.https.HttpsURLConnectionImpl.getOutputStream(HttpsURLConnectionImpl.java:250)
at com.google.bigtable.repackaged.com.google.api.client.http.javanet.NetHttpRequest.execute(NetHttpRequest.
java:77)
at com.google.bigtable.repackaged.com.google.api.client.http.HttpRequest.execute(HttpRequest.java:965)
at com.google.auth.oauth2.ServiceAccountCredentials.refreshAccessToken(ServiceAccountCredentials.java:222)
at com.google.cloud.bigtable.grpc.io.RefreshingOAuth2CredentialsInterceptor.refreshCredentialsWithRetry(Ref
reshingOAuth2CredentialsInterceptor.java:268)
at com.google.cloud.bigtable.grpc.io.RefreshingOAuth2CredentialsInterceptor.doRefresh(RefreshingOAuth2Crede
ntialsInterceptor.java:238)
at com.google.cloud.bigtable.grpc.io.RefreshingOAuth2CredentialsInterceptor$1.run(RefreshingOAuth2Credentia
lsInterceptor.java:166)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)

[vc13819]

Tried upgrading to bigtable client 0.2.3. This is the error I am getting now. (I have 'com.google.auth:google-auth-library-appengine:0.3.1' in the classpath)

Caused by: java.io.IOException: Application Default Credentials failed to create the Google App Engine service account credentials class com.google.bigtable.repackaged.com.google.auth.appengine.AppEngineCredentials. Check that the component 'google-auth-library-appengine' is deployed.
at com.google.bigtable.repackaged.com.google.auth.oauth2.DefaultCredentialsProvider.tryGetAppEngineCredential(DefaultCredentialsProvider.java:241)
at com.google.bigtable.repackaged.com.google.auth.oauth2.DefaultCredentialsProvider.getDefaultCredentialsUnsynchronized(DefaultCredentialsProvider.java:138)
at com.google.bigtable.repackaged.com.google.auth.oauth2.DefaultCredentialsProvider.getDefaultCredentials(DefaultCredentialsProvider.java:67)
at com.google.bigtable.repackaged.com.google.auth.oauth2.GoogleCredentials.getApplicationDefault(GoogleCredentials.java:54)
at com.google.cloud.bigtable.config.CredentialFactory.getApplicationDefaultCredential(CredentialFactory.java:181)
at com.google.cloud.bigtable.config.CredentialFactory.getCredentials(CredentialFactory.java:100)
at com.google.cloud.bigtable.grpc.io.CredentialInterceptorCache.getCredentialsInterceptor(CredentialInterceptorCache.java:85)
at com.google.cloud.bigtable.grpc.BigtableSession$6.call(BigtableSession.java:317)
at com.google.cloud.bigtable.grpc.BigtableSession$6.call(BigtableSession.java:309)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
... 1 more
Caused by: java.lang.ClassNotFoundException: com.google.bigtable.repackaged.com.google.auth.appengine.AppEngineCredentials
at java.net.URLClassLoader$1.run(URLClassLoader.java:366)
at java.net.URLClassLoader$1.run(URLClassLoader.java:355)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.URLClassLoader.findClass(URLClassLoader.java:354)
at java.lang.ClassLoader.loadClass(ClassLoader.java:425)
at java.lang.ClassLoader.loadClass(ClassLoader.java:358)
at org.eclipse.jetty.webapp.WebAppClassLoader.loadClass(WebAppClassLoader.java:450)
at org.eclipse.jetty.webapp.WebAppClassLoader.loadClass(WebAppClassLoader.java:403)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:195)
at com.google.bigtable.repackaged.com.google.auth.oauth2.DefaultCredentialsProvider.forName(DefaultCredentialsProvider.java:266)
at com.google.bigtable.repackaged.com.google.auth.oauth2.DefaultCredentialsProvider.tryGetAppEngineCredential(DefaultCredentialsProvider.java:225)
... 12 more

[sduskis]

google-auth-library-appengine was added to the project. I put out a new 0.2.5-SNAPSHOT version that includes that library. You'll need to add https://oss.sonatype.org/content/repositories/snapshots to your repositories section in maven in order to access it.

[vc13819]

Yes I did add the snapshot repository. I was able to successfully build the
application. It even worked for a while, and after sometime started giving
this error (and once this error started to show up, it was there for all
requests). Going back to specifying GOOGLE_APPLICATION_CREDENTIALS worked
again.

This is the error stacktrace:
Caused by: com.google.bigtable.repackaged.io.grpc.StatusRuntimeException:
UNAUTHENTICATED: Request had invalid authentication credentials. at
com.google.bigtable.repackaged.io.grpc.Status.asRuntimeException(
Status.java:431
https://console.cloud.google.com/debug/fromlog?appModule=default&appVersion=20160331t103723&file=com%2Fgoogle%2Fbigtable%2Frepackaged%2Fio%2Fgrpc%2FStatus.java&line=431&timestampNanos=1459406790815480000&project=bigtable-1152)
at com.google.cloud.bigtable.grpc.scanner.ReadRowsResponseListener.onClose(
ReadRowsResponseListener.java:72
https://console.cloud.google.com/debug/fromlog?appModule=default&appVersion=20160331t103723&file=com%2Fgoogle%2Fcloud%2Fbigtable%2Fgrpc%2Fscanner%2FReadRowsResponseListener.java&line=72&timestampNanos=1459406790815480000&project=bigtable-1152)
at
com.google.bigtable.repackaged.io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$3.runInContext(
ClientCallImpl.java:462
https://console.cloud.google.com/debug/fromlog?appModule=default&appVersion=20160331t103723&file=com%2Fgoogle%2Fbigtable%2Frepackaged%2Fio%2Fgrpc%2Finternal%2FClientCallImpl.java&line=462&timestampNanos=1459406790815480000&project=bigtable-1152)
at com.google.bigtable.repackaged.io.grpc.internal.ContextRunnable.run(
ContextRunnable.java:54
https://console.cloud.google.com/debug/fromlog?appModule=default&appVersion=20160331t103723&file=com%2Fgoogle%2Fbigtable%2Frepackaged%2Fio%2Fgrpc%2Finternal%2FContextRunnable.java&line=54&timestampNanos=1459406790815480000&project=bigtable-1152)
at
com.google.bigtable.repackaged.io.grpc.internal.SerializingExecutor$TaskRunner.run(
SerializingExecutor.java:154
https://console.cloud.google.com/debug/fromlog?appModule=default&appVersion=20160331t103723&file=com%2Fgoogle%2Fbigtable%2Frepackaged%2Fio%2Fgrpc%2Finternal%2FSerializingExecutor.java&line=154&timestampNanos=1459406790815480000&project=bigtable-1152)
... 3 more

On Fri, Apr 1, 2016 at 2:57 AM, Solomon Duskis notifications@github.com
wrote:

google-auth-library-appengine was added to the project. I put out a new
0.2.5-SNAPSHOT version that includes that library. You'll need to add
https://oss.sonatype.org/content/repositories/snapshots to your
repositories section in maven in order to access it.

—
You are receiving this because you authored the thread.
Reply to this email directly or view it on GitHub
#750 (comment)

[sduskis]

This seems to have been fixed with the latest release of cloud bigtable client and the work we did on the google auth library to fix the underlying issue. I'm going to close this. If this is still a problem, we should reopen this bug.

[vc13819]

The error now comes after days not hours. A restart always fixes it. Some problem with refreshing access tokens (look at the very end of the trace). Again some "repackaged" classes. Something escaped shading?

java.util.concurrent.ExecutionException: java.lang.RuntimeException: com.google.cloud.bigtable.grpc.io.IOExceptionWithStatus: Error in response stream
at java.util.concurrent.FutureTask.report(FutureTask.java:122)
at java.util.concurrent.FutureTask.get(FutureTask.java:188)
at com.yawasa.server.storage.RawTopicTable.freeFutures(RawTopicTable.java:187)
at com.yawasa.server.storage.RawTopicTable.get(RawTopicTable.java:105)
at com.yawasa.server.acl.AclTopicTable.getInternal(AclTopicTable.java:82)
at com.yawasa.server.acl.AclTopicTable.get(AclTopicTable.java:43)
at com.yawasa.server.ReadHandler.doPost(ReadHandler.java:42)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:644)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:725)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:808)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1669)
at com.google.apphosting.utils.servlet.ParseBlobUploadFilter.doFilter(ParseBlobUploadFilter.java:125)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
at com.google.apphosting.runtime.jetty9.SaveSessionFilter.doFilter(SaveSessionFilter.java:37)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
at com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:50)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:553)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)
at com.google.apphosting.vmruntime.jetty9.VmRuntimeWebAppContext.doScope(VmRuntimeWebAppContext.java:299)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:215)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:110)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)
at org.eclipse.jetty.server.Server.handle(Server.java:497)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:310)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)
at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.RuntimeException: com.google.cloud.bigtable.grpc.io.IOExceptionWithStatus: Error in response stream
at org.apache.hadoop.hbase.client.AbstractClientScanner$1.hasNext(AbstractClientScanner.java:97)
at com.yawasa.server.storage.TopicPopulator.get(TopicPopulator.java:59)
at com.yawasa.server.storage.RawTopicTable.get(RawTopicTable.java:207)
at com.yawasa.server.storage.RawTopicTable.access$000(RawTopicTable.java:47)
at com.yawasa.server.storage.RawTopicTable$1.call(RawTopicTable.java:97)
at com.yawasa.server.storage.RawTopicTable$1.call(RawTopicTable.java:94)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
... 1 more
Caused by: com.google.cloud.bigtable.grpc.io.IOExceptionWithStatus: Error in response stream
at com.google.cloud.bigtable.grpc.scanner.ResultQueueEntry$ExceptionResultQueueEntry.getResponseOrThrow(ResultQueueEntry.java:66)
at com.google.cloud.bigtable.grpc.scanner.ResponseQueueReader.getNextMergedRow(ResponseQueueReader.java:69)
at com.google.cloud.bigtable.grpc.scanner.StreamingBigtableResultScanner.next(StreamingBigtableResultScanner.java:42)
at com.google.cloud.bigtable.grpc.scanner.StreamingBigtableResultScanner.next(StreamingBigtableResultScanner.java:27)
at com.google.cloud.bigtable.grpc.scanner.ResumingStreamingResultScanner.next(ResumingStreamingResultScanner.java:158)
at com.google.cloud.bigtable.grpc.scanner.ResumingStreamingResultScanner.next(ResumingStreamingResultScanner.java:44)
at com.google.cloud.bigtable.hbase.adapters.BigtableResultScannerAdapter$1.next(BigtableResultScannerAdapter.java:43)
at org.apache.hadoop.hbase.client.AbstractClientScanner$1.hasNext(AbstractClientScanner.java:94)
... 11 more
Caused by: com.google.bigtable.repackaged.io.grpc.StatusRuntimeException: UNKNOWN
at com.google.bigtable.repackaged.io.grpc.Status.asRuntimeException(Status.java:431)
at com.google.cloud.bigtable.grpc.scanner.ReadRowsResponseListener.onClose(ReadRowsResponseListener.java:72)
at com.google.bigtable.repackaged.io.grpc.ClientInterceptors$CheckedForwardingClientCall.start(ClientInterceptors.java:172)
at com.google.cloud.bigtable.grpc.async.BigtableAsyncUtilities$Default.start(BigtableAsyncUtilities.java:110)
at com.google.cloud.bigtable.grpc.async.BigtableAsyncUtilities$Default.asyncServerStreamingCall(BigtableAsyncUtilities.java:94)
at com.google.cloud.bigtable.grpc.BigtableDataGrpcClient.streamRows(BigtableDataGrpcClient.java:364)
at com.google.cloud.bigtable.grpc.BigtableDataGrpcClient.access$100(BigtableDataGrpcClient.java:75)
at com.google.cloud.bigtable.grpc.BigtableDataGrpcClient$5.createScanner(BigtableDataGrpcClient.java:153)
at com.google.cloud.bigtable.grpc.scanner.ResumingStreamingResultScanner.(ResumingStreamingResultScanner.java:133)
at com.google.cloud.bigtable.grpc.scanner.ResumingStreamingResultScanner.(ResumingStreamingResultScanner.java:122)
at com.google.cloud.bigtable.grpc.BigtableDataGrpcClient.readRows(BigtableDataGrpcClient.java:330)
at com.google.cloud.bigtable.hbase.BigtableTable.getScanner(BigtableTable.java:214)
... 11 more
Caused by: java.io.IOException: Could not read headers
at com.google.cloud.bigtable.grpc.io.RefreshingOAuth2CredentialsInterceptor.refreshCredentialsWithRetry(RefreshingOAuth2CredentialsInterceptor.java:318)
at com.google.cloud.bigtable.grpc.io.RefreshingOAuth2CredentialsInterceptor.doRefresh(RefreshingOAuth2CredentialsInterceptor.java:256)
at com.google.cloud.bigtable.grpc.io.RefreshingOAuth2CredentialsInterceptor.syncRefresh(RefreshingOAuth2CredentialsInterceptor.java:192)
at com.google.cloud.bigtable.grpc.io.RefreshingOAuth2CredentialsInterceptor.getHeader(RefreshingOAuth2CredentialsInterceptor.java:219)
at com.google.cloud.bigtable.grpc.io.RefreshingOAuth2CredentialsInterceptor.updateHeaders(RefreshingOAuth2CredentialsInterceptor.java:177)
at com.google.cloud.bigtable.grpc.io.ChannelPool$1.checkedStart(ChannelPool.java:140)
at com.google.bigtable.repackaged.io.grpc.ClientInterceptors$CheckedForwardingClientCall.start(ClientInterceptors.java:164)
... 20 more
Caused by: com.google.apphosting.api.ApiProxy$ArgumentException: An error occurred parsing (locally or remotely) the arguments to APP_IDENTITY_SERVICE.GetAccessToken().
at com.google.apphosting.vmruntime.VmApiProxyDelegate.convertApiResponseRpcErrorToException(VmApiProxyDelegate.java:399)
at com.google.apphosting.vmruntime.VmApiProxyDelegate.convertRemoteError(VmApiProxyDelegate.java:343)
at com.google.apphosting.vmruntime.VmApiProxyDelegate.runSyncCall(VmApiProxyDelegate.java:187)
at com.google.apphosting.vmruntime.VmApiProxyDelegate.makeApiCall(VmApiProxyDelegate.java:154)

11:51:40.187

at com.google.apphosting.vmruntime.VmApiProxyDelegate.makeSyncCallWithTimeout(VmApiProxyDelegate.java:128)
at com.google.apphosting.vmruntime.VmApiProxyDelegate.makeSyncCall(VmApiProxyDelegate.java:117)
at com.google.apphosting.vmruntime.VmApiProxyDelegate.makeSyncCall(VmApiProxyDelegate.java:60)
at com.google.apphosting.api.ApiProxy.makeSyncCall(ApiProxy.java:114)
at com.google.apphosting.api.ApiProxy.makeSyncCall(ApiProxy.java:66)
at com.google.appengine.api.appidentity.AppIdentityServiceImpl.getAccessTokenUncached(AppIdentityServiceImpl.java:232)
at com.google.appengine.api.appidentity.AppIdentityServiceImpl.getAccessToken(AppIdentityServiceImpl.java:291)
at com.google.bigtable.repackaged.com.google.auth.appengine.AppEngineCredentials.refreshAccessToken(AppEngineCredentials.java:77)
at com.google.cloud.bigtable.grpc.io.RefreshingOAuth2CredentialsInterceptor.refreshCredentialsWithRetry(RefreshingOAuth2CredentialsInterceptor.java:286)

[sduskis]

This seems to be a problem getting credentials on appengine. This looks like a runtime issue, not a build time problem, like a shading issue. @lesv, can you please take a look?

[lesv]

Hi - could you verify that you are using the 0.9.0 client?

[lesv]

Also, is this an interactive request or the result of a long processing that just happens to be on GAE Flex (ie. very long running GET)?

(I'd like to figure out what I need to simulate)