Re: [grpc-io] suggestions for debugging/tracking down "invalid protobuf byte sequence"

[Kun Zhang]

Hi Steven,

It seems the original post has been deleted. Was the issue resolved?

On Fri, Dec 23, 2016 at 12:52 PM, Steven Parkes <smpa...@smparkes.net> wrote:

We're getting a lot of "Invalid protobuf byte sequence" errors over a bidi streaming service call.

The server is grpc-java and the client go.

The message that seems to be causing the issue is a relatively large message of repeated maps. One example is around 400kB.

It doesn't look like it's deterministically repeatable.

We seem to be getting the "invalid" message on both sides, though it's a little hard (for me) to tell if, on the go side, it's just reiterating what the java side told it.

The java side is definitely failing trying to parse a buffer.

The cause of the invalid error isn't consistent: sometimes its a zero tag, sometimes bad UTF-8, etc., so it appears to be a bad buffer.

I added some very hacky debugging and in the bad UTF-8 case, which confirms it looks like a bad buffer. There's the prefix of a normal string and then a couple of nulls.

Trying to figure out what in the middle of all of this to try to observe to narrow things down. I did turn on the netty logging though I don't have the background to get much out of it at this point.

grpc-java is 1.0.3. Go grpc is up-to-date/63bd55dfbf781b183216d2dd4433a659c947648a according to glide.

Annecdotally, it seems to happen only a little at the start of the service and then increase in frequency (not sure if this is load based ... a bit hard to tell that right now.)

Also, just saw this for the first time:

2016-12-23T20:43:49.213Z [grpc-default-worker-ELG-3-3] ERROR io.netty.util.ResourceLeakDetector - LEAK: ByteBuf.release() was not called before it's garbage-collected. Enable advanced leak reporting to find out where the leak occurred. To enable advanced leak reporting, specify the JVM option '-Dio.netty.leakDetection.level=adv

Typical error message:

2016-12-23T19:52:23.597Z [grpc-default-executor-4] ERROR io.grpc.internal.SerializingExecutor - Exception while executing runnable io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$1@6e71d62c

io.grpc.StatusRuntimeException: INTERNAL: Invalid protobuf byte sequence

        at io.grpc.Status.asRuntimeException(Status.java:532)

        at io.grpc.protobuf.lite.ProtoLiteUtils$2.parse(ProtoLiteUtils.java:175)

        at io.grpc.protobuf.lite.ProtoLiteUtils$2.parse(ProtoLiteUtils.java:96)

        at io.grpc.MethodDescriptor.parseRequest(MethodDescriptor.java:267)

        at io.grpc.internal.ServerCallImpl$ServerStreamListenerImpl.messageRead(ServerCallImpl.java:241)

        at io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$1.runInContext(ServerImpl.java:557)

        at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:52)

        at io.grpc.internal.SerializingExecutor$TaskRunner.run(SerializingExecutor.java:154)

        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:745)

Caused by: com.google.protobuf.InvalidProtocolBufferException: Protocol message had invalid UTF-8.

        at com.google.protobuf.InvalidProtocolBufferException.invalidUtf8(InvalidProtocolBufferException.java:144)

        at com.google.protobuf.CodedInputStream$ArrayDecoder.readStringRequireUtf8(CodedInputStream.java:734)

        at io.ascend.protos.core.Value.<init>(Value.java:65)

        at io.ascend.protos.core.Value.<init>(Value.java:17)

        at io.ascend.protos.core.Value$1.parsePartialFrom(Value.java:1553)

        at io.ascend.protos.core.Value$1.parsePartialFrom(Value.java:1548)

        at io.ascend.protos.core.Value$Builder.mergeFrom(Value.java:844)

        at io.ascend.protos.core.Value$Builder.mergeFrom(Value.java:660)

        at com.google.protobuf.CodedInputStream$ArrayDecoder.readMessage(CodedInputStream.java:799)

        at com.google.protobuf.MapEntryLite.parseField(MapEntryLite.java:128)

        at com.google.protobuf.MapEntryLite.parseEntry(MapEntryLite.java:184)

        at com.google.protobuf.MapEntry.<init>(MapEntry.java:106)

        at com.google.protobuf.MapEntry.<init>(MapEntry.java:51)

        at com.google.protobuf.MapEntry$Metadata$1.parsePartialFrom(MapEntry.java:71)

        at com.google.protobuf.MapEntry$Metadata$1.parsePartialFrom(MapEntry.java:65)

        at com.google.protobuf.CodedInputStream$ArrayDecoder.readMessage(CodedInputStream.java:815)

        at io.ascend.protos.core.Struct.<init>(Struct.java:57)

        at io.ascend.protos.core.Struct.<init>(Struct.java:14)

        at io.ascend.protos.core.Struct$1.parsePartialFrom(Struct.java:673)

        at io.ascend.protos.core.Struct$1.parsePartialFrom(Struct.java:668)

        at com.google.protobuf.CodedInputStream$ArrayDecoder.readMessage(CodedInputStream.java:815)

        at io.ascend.protos.worker.RecordsRead.<init>(RecordsRead.java:52)

        at io.ascend.protos.worker.RecordsRead.<init>(RecordsRead.java:9)

        at io.ascend.protos.worker.RecordsRead$1.parsePartialFrom(RecordsRead.java:694)

        at io.ascend.protos.worker.RecordsRead$1.parsePartialFrom(RecordsRead.java:689)

        at com.google.protobuf.CodedInputStream$ArrayDecoder.readMessage(CodedInputStream.java:815)

        at io.ascend.protos.worker.Update.<init>(Update.java:106)

        at io.ascend.protos.worker.Update.<init>(Update.java:9)

        at io.ascend.protos.worker.Update$1.parsePartialFrom(Update.java:1942)

        at io.ascend.protos.worker.Update$1.parsePartialFrom(Update.java:1937)

        at com.google.protobuf.AbstractParser.parseFrom(AbstractParser.java:91)

        at com.google.protobuf.AbstractParser.parseFrom(AbstractParser.java:49)

        at io.grpc.protobuf.lite.ProtoLiteUtils$2.parseFrom(ProtoLiteUtils.java:180)

        at io.grpc.protobuf.lite.ProtoLiteUtils$2.parse(ProtoLiteUtils.java:172)

        ... 9 common frames omitted

--
You received this message because you are subscribed to the Google Groups "grpc.io" group.
To unsubscribe from this group and stop receiving emails from it, send an email to grpc-io+unsubscribe@googlegroups.com.
To post to this group, send email to grp...@googlegroups.com.
Visit this group at https://groups.google.com/group/grpc-io.
To view this discussion on the web visit https://groups.google.com/d/msgid/grpc-io/0b6a274a-ae50-4962-9dcd-ca9e6a94e1ed%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

- Kun

[Steven Parkes]

Yeah, I deleted it. A little embarrassed: the go client didn't have the necessary thread protection. The grpc-java tends to throw exceptions if you multithread it incorrectly but the grpc-go code (apparently) just intermixes bytes on the wire.