E1009 14:37:36.130832617 2404 proto_utils.h:185] assertion failed: GRPC_SLICE_END_PTR(slice) == msg.SerializeWithCachedSizesToArray(GRPC_SLICE_START_PTR(slice))

[pyssling]

Should this be an issue in the gRPC issue tracker?

Yes.

What version of gRPC and what language are you using?

grpc-1.6.1
protobuf-3.4.1

What operating system (Linux, Windows, …) and version?

Linux, Centos 7

What runtime / compiler are you using (e.g. python version or version of gcc)

gcc gcc (GCC) 4.8.5 20150623 (Red Hat 4.8.5-11)
(GCC) 4.8.5 20150623 (Red Hat 4.8.5-11)

What did you do?

We send messages over the server-streaming RPC. The RPC never terminates but continues to send messages to clients for the duration of their connection (days, weeks, months).

We are using the asynchronous API on the server side and requests are encapsulated in a call struct similar to the C++ example.

When running load tests on this solution we see a crash, the grpc library calls abort from an assert.

What did you expect to see?

We expected successful completion of the load test.

What did you see instead?

E1009 14:37:36.130832617 2404 proto_utils.h:185] assertion failed: GRPC_SLICE_END_PTR(slice) == msg.SerializeWithCachedSizesToArray(GRPC_SLICE_START_PTR(slice))

Program received signal SIGABRT, Aborted.
0x00007ffff529b1f7 in raise () from /lib64/libc.so.6
Missing separate debuginfos, use: debuginfo-install boost-regex-1.53.0-27.el7.x86_64 expat-2.1.0-10.el7_3.x86_64 fontconfig-2.10.95-11.el7.x86_64 freetype-2.4.11-15.el7.x86_64 glibc-2.17-196.el7.x86_64 keyutils-libs-1.5.8-3.el7.x86_64 krb5-libs-1.15.1-8.el7.x86_64 libICE-1.0.9-9.el7.x86_64 libSM-1.2.2-2.el7.x86_64 libX11-1.6.5-1.el7.x86_64 libXau-1.0.8-2.1.el7.x86_64 libXcursor-1.1.14-8.el7.x86_64 libXext-1.3.3-3.el7.x86_64 libXfixes-5.0.3-1.el7.x86_64 libXft-2.3.2-2.el7.x86_64 libXi-1.7.9-1.el7.x86_64 libXinerama-1.1.3-2.1.el7.x86_64 libXrandr-1.5.1-2.el7.x86_64 libXrender-0.9.10-1.el7.x86_64 libcom_err-1.42.9-10.el7.x86_64 libgcc-4.8.5-16.el7.x86_64 libicu-50.1.2-15.el7.x86_64 libjpeg-turbo-1.2.90-5.el7.x86_64 libmng-1.0.10-14.el7.x86_64 libpng-1.5.13-7.el7_2.x86_64 libselinux-2.5-11.el7.x86_64 libstdc++-4.8.5-16.el7.x86_64 libuuid-2.23.2-43.el7.x86_64 libxcb-1.12-1.el7.x86_64 libxml2-2.9.1-6.el7_2.3.x86_64 nss-softokn-freebl-3.28.3-8.el7_4.x86_64 openssl-libs-1.0.2k-8.el7.x86_64 pcre-8.32-17.el7.x86_64 qt3-3.3.8b-51.el7.x86_64 xz-libs-5.2.2-1.el7.x86_64 zlib-1.2.7-17.el7.x86_64
(gdb) bt
#0 0x00007ffff529b1f7 in raise () from /lib64/libc.so.6
#1 0x00007ffff529c8e8 in abort () from /lib64/libc.so.6
#2 0x00007ffff7841cd4 in grpc::CoreCodegen::assert_fail(char const*, char const*, int) ()
from /lib64/libgrpc++.so.1
#3 0x000000000061ed2f in grpc::SerializationTraits<SendPlanReply, void>::Serialize (msg=..., bp=0xae32d8,
own_buffer=0xae32e8) at /usr/include/grpc++/impl/codegen/proto_utils.h:183
#4 0x000000000061ead5 in grpc::CallOpSendMessage::SendMessage (this=0xae32d8, message=...,
options=...) at /usr/include/grpc++/impl/codegen/call.h:294
#5 0x000000000061e62e in grpc::CallOpSendMessage::SendMessage (this=0xae32d8, message=...)
at /usr/include/grpc++/impl/codegen/call.h:299
#6 0x000000000061e09b in grpc::ServerAsyncWriter::Write (this=0xae3240, msg=...,
tag=0xae31e0) at /usr/include/grpc++/impl/codegen/async_stream.h:709
...

Anything else we should know about your project / environment?

One thing of note here. The assert code looks like this:

int byte_size = msg.ByteSize();
if (byte_size <= internal::kGrpcBufferWriterMaxBufferLength) {
  grpc_slice slice = g_core_codegen_interface->grpc_slice_malloc(byte_size);
  GPR_CODEGEN_ASSERT(
      GRPC_SLICE_END_PTR(slice) ==
      msg.SerializeWithCachedSizesToArray(GRPC_SLICE_START_PTR(slice)));

And the documentation for SerializeWithCachedSizesToArray is here: https://developers.google.com/protocol-buffers/docs/reference/cpp/google.protobuf.message_lite and says

virtual uint8 *	SerializeWithCachedSizesToArray(uint8 * target) constA version of SerializeWithCachedSizesToArray, below, that does not guarantee deterministic serialization.

In other words, the byte_size seems to indicate a maximum, while the actual serialized message may use less bytes it seems? In which case the assert above is not valid I guess.

[pyssling]

@dgquintas @ctiller I see your names on this area of code, though it's tricky to trace the origin. Do you have any clue as to what could be going on?

[pyssling]

Ok. this seems to have been a programmer error involving a race condition. My apologies.