Intermittent error: UNAUTHENTICATED: Request had invalid authentication credentials.

[karthikv]

We've been using google cloud speech alongside these nodejs client bindings in production for many months now. Intermittently, we get the following error:

Error: 16 UNAUTHENTICATED: Request had invalid authentication credentials. Expected OAuth 2 access token, login cookie or other valid authentication credential. See https://developers.google.com/identity/sign-in/web/devconsole-project.

at Object.exports.createStatusError (node_modules/grpc/src/common.js line 87 col 15)
at ClientDuplexStream._emitStatusIfDone (node_modules/grpc/src/client.js line 235 col 26)
at ClientDuplexStream._receiveStatus (node_modules/grpc/src/client.js line 213 col 8)
at Object.onReceiveStatus (node_modules/grpc/src/client_interceptors.js line 1290 col 15)
at InterceptingListener._callNext (node_modules/grpc/src/client_interceptors.js line 564 col 42)
at InterceptingListener.onReceiveStatus (node_modules/grpc/src/client_interceptors.js line 614 col 8)

In the last 30 days, we've received ~100 of these errors from about over 40,000 streaming recognize sessions, so this only happens in about ~0.25% of cases. In all the remaining cases, the streaming recognize works as expected. Note that this problem has been going on since we started using this library, not just for the past month.

Environment details

• OS: debian jessie on GCE
• Node.js version: 10.13.0
• npm version: 6.4.1
• @google-cloud/speech version: 2.0.0

Steps to reproduce

There's not a clear reproduction case--this error comes about naturally after running streaming recognizes for some extended period of time. My guess here is that the access tokens are sometimes not refreshed in a timely manner, or perhaps some clock skew is causing them to be invalid.

Here are some issues I've found in the python client libraries that resemble the problem I'm seeing, in case this is useful:

• pubsub publisher sometimes fails with StatusCode.UNAUTHENTICATED, Deadline Exceeded google-cloud-python#5014
• AbortionError(code=StatusCode.UNAUTHENTICATED, details="Request had invalid authentication credentials.") google-cloud-python#2684
• _grpc_catch_rendezvous Unauthorized - Datastore - AppEngine Flexible google-cloud-python#3259

I'll definitely try upgrading to the latest library version as a first step.

[karthikv]

Just want to follow up here: any idea if/when this will be looked into? We're heavy users of the speech API, and we're encountering this 30+ times a day, which is a poor experience for our users. Upgrading to 2.2.0 doesn't fix this issue.

[JustinBeckwith]

Greetings! What execution environment are you running in? Cloud Functions? App Engine? Local?

[karthikv]

We're seeing this error on GCE using debian jessie. The first post has a few more details about the environment.

[JustinBeckwith]

Apologies for missing that. Are you relying application default authentication, or are you packaging a keyfile along with your sources? If you would be willing - I'd love to know if this reproduces with a local keyfile instead of relying on the GCE metadata server. May give us a clue to what's happening here.

[karthikv]

@JustinBeckwith I'm currently using a keyfile.

[JustinBeckwith]

Ohhhkay that's wild. Are you using other services by chance? I'm curious if this is something specific to the speech API, or something you're seeing elsewhere.

Adding @theacodes as she may have insights here as well.

[theacodes]

We're not seeing this in other languages, so I'm hesitant to think it's a server or frontend issue.

I'm wondering a few things:

1. Does this library eagerly refresh credentials if expire_time < now - clock_skew_buffer?
2. How long are these streaming requests?
3. How long are the clients your using hanging around?
4. Is it possible that the credentials expire during the stream and the service then closes the stream with unauthenticated?

[karthikv]

@JustinBeckwith We use storage and text-to-speech as well, but I haven't seen any similar issues with those services.

@theacodes

1. I assume this is a question for @JustinBeckwith or other maintainers of this library.
2. Most of our streams are <= 30 seconds. Streaming requests are required to be less than 65 seconds as per the limits.
3. We have a service that initiates and processes multiple streaming recognize sessions throughout the day, and it's always running. Does this answer your question?
4. Good question, I currently don't have insight into when these errors occur with respect to the streaming request. Perhaps they happen in the middle of the stream, as you stated, or maybe they happen at the beginning. @JustinBeckwith if I add a handler for the "error" event on the stream returned from streamingRecognize(), will I be able to track this error? I can add some monitoring to assess how long the error takes to trigger after the stream has begun.

[callmehiphop]

@sduskis @ajaaym just an FYI, this sounds pretty similar to what we're seeing in PubSub.

[sduskis]

@callmehiphop, I agree. Streaming RPCs need some sort of retry on UNAUTHORIZED, if they've been open for a while.

googleapis/nodejs-pubsub#318 showed similar issues, and it references this same behavior in clients with different languages.

[JustinBeckwith]

Bringing in @jadekler for the retry grpc discussion 🙃

[jeanbza]

As @theacodes alluded to in #243 (comment) (question #1), I expect not to need retry on UNAUTHENTICATED as long as the auth library is refreshing credentials before the deadline.

Is that not the case in python/java auth? Or, perhaps I'm missing something.

(I defer to @theacodes and @broady who know more about auth and auth refresh than I do, though)

[sduskis]

@jadekler, long running streaming APIs have interesting failure modes relating to credentials. The Token is passed with the RPC is started, but it never changes even when the auth token expires.

Let's say the auth token is 50 minutes old, and a new streaming RPC is started. If the RPC is open past the auth expiration, the service may send UNAUTHORIZED.

[jeanbza]

That makes sense, but it doesn't seem like we need that in Go. I guess I don't really understand why. @broady do you know how this stuff works? cc @dfawley

[jeanbza]

@dfawley mentions it's server-implementation specific. It's definitely plausible that a server might just check once - at the start of the RPC (the long-lived stream). I naively expect this to be the norm? It might be good for a support engineer to help debug the user's project to understand where the error code is coming from, and what exactly caused it.

[callmehiphop]

@bcoe FYI

[bcoe]

@callmehiphop aha! this does sound like the same thing; I'm seeing this crop up about 1,000,000 pub/sub requests in the pub/sub API.

[stephenplusplus]

@karthikv, we have pushed a fix recently that more eagerly refreshes an access token. Have you still been experiencing this issue using the latest dependencies?

[stephenplusplus]

It seems like we've addressed this issue in the auth library by eagerly refreshing tokens, so let's close for now, and re-open if it emerges again.

[karthikv]

@stephenplusplus We'll try the new version (I assume you're referring to google-auth-library@5.3.0 or later) and report back if we see the same issue arise!

[stephenplusplus]

Yes, exactly. Thank you for linking that, and sounds good!

[eug48]

@stephenplusplus Thanks. I haven't seen this error since switching to the updated auth library, though it occurred quite infrequently for me. The update did take some fiddling though since both nodejs-common and nodejs-pubsub have "google-auth-library": "^5.0.0" - so yarn didn't update the library by default..

[karthikv]

@stephenplusplus We haven't experienced any issues in the past week of using the updated library. Thank you!