nodejs-datastore: Metadata key contains illegal characters

We’ve started noticing a new error in production (and in staging env also) that happens ~50 times a day for us (for many thousands or maybe even millions of calls per day, don’t have exact number). It looks like this in a stacktrace:


unhandledRejection:  { 
Error: Metadata key "a" contains illegal characters     
at Http2CallStream.call.on (/ncbackend3/node_modules/@grpc/grpc-js/build/src/client.js:102:45)     
at Http2CallStream.emit (events.js:194:15)     
at Http2CallStream.EventEmitter.emit (domain.js:459:23)     
at Http2CallStream.endCall (/ncbackend3/node_modules/@grpc/grpc-js/build/src/call-stream.js:74:18)     
at ClientHttp2Stream.stream.on (/ncbackend3/node_modules/@grpc/grpc-js/build/src/call-stream.js:205:30)     
at ClientHttp2Stream.emit (events.js:189:13)     
at ClientHttp2Stream.EventEmitter.emit (domain.js:459:23)     at emit (internal/http2/core.js:236:8)     
at process._tickCallback (internal/process/next_tick.js:63:19)  
 code: 2,   
details:    'Metadata key "a\u0000\u0000\u0000" contains illegal characters',   
metadata: Metadata { internalRepr: Map {} },   
note:    'Exception occurred in retry method that was not classified as transient' }

I’ve even seen this error myself once while calling a certain endpoint that was doing 1 query and 2-3 getById calls to Datastore. So, no saves was made, only querying.

This error is not reproducible all the time, as I mentioned, rather “rare”, but still noticeable (~50 hard errors every day, that end up in http 500 errors for our api users).

I don’t know how to dig further and provide other helpful info. Important to note that it only happened after updating from ^3.0.0 (latest version in 3.x.x) to 4.0.0. I’m assuming the error could somewhere downstream (in grpc-js itself) that was updated as a sub-dependency. We’re on the latest version of everything as of today (yarn upgrade was done and we have no deps pinned).

ps: forgot to add that the “key” in the metadata has different values in each other error (we see it in Sentry), examples (err.message here):

Metadata key "a" contains illegal characters
Metadata key " ’û·" contains illegal characters
Metadata key " ’`ñ" contains illegal characters
Metadata key " rð" contains illegal characters
Metadata key " òe×" contains illegal characters
Metadata key " ’wâ" contains illegal characters
...

pps: we were using .runQuery() method with 2 simple filters by number fields and .get(key) (that’s what I called getById). Same code in 3.x.x version worked just fine.

Noticed that a occured more often than others.

Environment details

  • OS: node:10-alpine official docker image
  • Node.js version: 10.15.3
  • npm version: not applicable
  • @google-cloud/datastore version: 4.0.0

About this issue

  • Original URL
  • State: closed
  • Created 5 years ago
  • Reactions: 2
  • Comments: 46 (17 by maintainers)

Commits related to this issue

Most upvoted comments

Just confirming I’m seeing this frequently as well, but also not reproducibly. Retrying the request in question almost always succeeds. It happens regardless of whether there are simultaneous parallel requests.

Our project contains get, runQuery, and upsert calls, and I’ve seen it happen with all of them.

@klon This is a valid question.

To answer your question: this is not some external library we randomly started using for no reason, it’s a library we develop and is supposed to be a replacement of the existing grpc library (that is based on C++ code compiled into Node.js binary, which makes it hard to use it everywhere).

It’s indeed marked as beta, but it still makes sense to use it and not grpc for several reasons (module size, install time, load time, platform binary dependency in grpc). Before we switched to @grpc/grpc-js, we tested it across all 50+ client libraries we support for several months in a row, and made sure there are no differences in behavior. Also, we made sure the rollback to the original grpc is possible and easy (and it actually is a helpful workaround in this particular case). Finally, switching to @grpc/grpc-js was a semver major bump for all client libraries (including Datastore library) that communicates that this is somewhat big change.

It’s sad to see that this particular edge case was not caught by our tests.

Bugs do happen, we apologize for this inconvenience this caused for you and other folks in this thread. This bug would’ve likely happened even if @grpc/grpc-js was called v1.0.0 and changed the release status to general availability.

I guess we could’ve done somewhat better job communicating this change (that happened within our latest semver major release) and explaining a way to rollback to grpc in the documentation. However, I must note that this is the only grpc-js-related issue we got so far, out of tens of client libraries switched, and gRPC folks are looking into this and I hope we’ll have a fix for this issue.

Thanks! -Alex

@kirillgroshkov @kmontag The main difference between v3.x and v4.x under the hood is the replacement of the original grpc (which uses C++ code compiled into Node.js binary) with the new @grpc/grpc-js. The error you folks see comes from grpc-js so it might be totally possible that the upgrade is causing this. Similar metadata check exists in grpc as well but it has completely different logic.

The good news is that you can keep using the C++ grpc for the time being by passing it to the client constructor:

npm install grpc
const grpc = require('grpc'); // not '@grpc/grpc-js'
const {Datastore} = require('@google-cloud/datastore');
const projectId = 'YOUR_PROJECT_ID';
const datastore = new Datastore({
  projectId,
  grpc   // <-- passing it down to the client
});

I would really appreciate it if you folks try that and update this issue with the results (e.g. if the errors disappear or not). This will help us report a bug to gRPC developers.

Thanks!

Your fix was to bump @grpc/grpc-js to v0.5.2?

$ npm ls @grpc/grpc-js
myapp
├─┬ @google-cloud/datastore@3.1.2
│ └─┬ google-gax@0.25.6
│   └── @grpc/grpc-js@0.3.6
└─┬ @google-cloud/logging-bunyan@0.10.1
  └─┬ @google-cloud/logging@4.5.2
    └─┬ google-gax@0.25.6
      └── @grpc/grpc-js@0.3.6

I dropped back down to 3 and am not seeing issues in the last hour or so

Deployed it yesterday. So far 0 errors, looks promising.

@kirillgroshkov @kmontag @klon @csidell-earny @chrishiestand

Hey folks,

We have released google-gax v1.1.5 that pulls @grpc/grpc-js v0.5.2 in which the invalid headers (that are coming from Node.js http2 module) are printed in a warning, but do not throw exception. Please upgrade your dependencies, it should fix the problem for you folks (but please keep posting those warnings here and/or to the Node.js issue https://github.com/grpc/grpc-node/pull/962 since it might help understand what’s going on in http2 module).

@chrishiestand Thank you so much for your help with debugging!

If you ever see a headers block with one of the bad strings that doesn’t have a lot of zeros (like " �wâ") it would be good to see what that headers block looks like too.

@alexander-fenster here’s the headers from a single function call

Good headers: [Object: null prototype] {
 ':status': 200,
 'content-disposition': 'attachment',
 'content-type': 'application/grpc',
 date: 'Wed, 10 Jul 2019 23:05:01 GMT',
 'alt-svc': 'quic=":443"; ma=2592000; v="46,43,39"'
}
Good headers: [Object: null prototype] {
 ':status': 200,
 'content-disposition': 'attachment',
 'content-type': 'application/grpc',
 date: 'Wed, 10 Jul 2019 23:05:01 GMT',
 'alt-svc': 'quic=":443"; ma=2592000; v="46,43,39"'
}
Good headers: [Object: null prototype] {
 ':status': 200,
 'content-disposition': 'attachment',
 'content-type': 'application/grpc',
 date: 'Wed, 10 Jul 2019 23:05:01 GMT',
 'alt-svc': 'quic=":443"; ma=2592000; v="46,43,39"'
}
Good headers: [Object: null prototype] {
 ':status': 200,
 'content-disposition': 'attachment',
 'content-type': 'application/grpc',
 date: 'Wed, 10 Jul 2019 23:05:01 GMT',
 'alt-svc': 'quic=":443"; ma=2592000; v="46,43,39"'
}
Good headers: [Object: null prototype] {
 ':status': 200,
 'content-disposition': 'attachment',
 'content-type': 'application/grpc',
 date: 'Wed, 10 Jul 2019 23:05:01 GMT',
 'alt-svc': 'quic=":443"; ma=2592000; v="46,43,39"'
}
Good headers: [Object: null prototype] {
 ':status': 200,
 'content-disposition': 'attachment',
 'content-type': 'application/grpc',
 date: 'Wed, 10 Jul 2019 23:05:01 GMT',
 'alt-svc': 'quic=":443"; ma=2592000; v="46,43,39"'
}
Good headers: [Object: null prototype] {
 ':status': 200,
 'content-disposition': 'attachment',
 'content-type': 'application/grpc',
 date: 'Wed, 10 Jul 2019 23:05:01 GMT',
 'alt-svc': 'quic=":443"; ma=2592000; v="46,43,39"'
}
Good headers: [Object: null prototype] {
 ':status': 200,
 'content-disposition': 'attachment',
 'content-type': 'application/grpc',
 date: 'Wed, 10 Jul 2019 23:05:02 GMT',
 'alt-svc': 'quic=":443"; ma=2592000; v="46,43,39"'
}

@alexander-fenster

 Bad headers: [Object: null prototype] {
   ':status': 200,
   'content-disposition': 'attachment',
   'content-type': 'application/grpc',
   'A\u0000\u0000\u0000': 'Wed, 10 Jul 2019 22:37:34 GMT',
   'alt-svc': 'quic=":443"; ma=2592000; v="46,43,39"'
 }
 
 "Metadata key \"a\u0000\u0000\u0000\" contains illegal characters

@chrishiestand Sorry it wasn’t a reference to the original problem but the one mentioned by @kirillgroshkov

Also confirming the issue is still present while using @google-cloud/datastore v4.1.3 and google-gax v1.1.4. I used the grpc workaround and hadn’t re-tested until now.

"Metadata key \"   \u0004\" contains illegal characters"