For those googling this in the future, the problem was in my server code. The server was responding to the request with: ERROR: Code: Unknown Message: Unexpected error in RPC handling
...it just didn't look like it was working in BloomRPC. I was finally able to get the request to work in grpcurl. The message "Failed to dial target host ... tls: first record does not look like a TLS handshake" was due to me not passing "-plaintext" to the grpcurl command. On Friday, 15 November 2019 11:14:56 UTC-5, [email protected] wrote: > > Hi all, thanks in advance and I hope this is the right forum to ask this > question. > > I've got a simple gRPC c++ server application that works fine locally (on > macOS). I can build and run the app and query it successfully with > BloomRPC. When I run the same app within Docker (with the port open, of > course) it receives the request, but the response never makes it back to > the client. I'm giving some code snippets, and at the end I'll post the > gRPC debug output. > > The app establishes a server via this code: > //... snip > std::string serverAddress = "0.0.0.0:50051"; > > grpc::ServerBuilder builder; > > builder.AddListeningPort(serverAddress, > grpc::InsecureServerCredentials()); > > builder.RegisterService(&service); > > std::unique_ptr<grpc::Server> server(builder.BuildAndStart()); > > std::cout << "Server startup successful, listening on " << serverAddress > << std::endl; > > server->Wait(); > > exit(0); > > > > I am building and linking the static libraries of gRPC and protobuf. > Relevant dockerfile snippet that shows my build environment: > WORKDIR /repos > > RUN git clone -b v1.24.3 https://github.com/grpc/grpc > > WORKDIR /repos/grpc > > RUN git submodule update --init > > WORKDIR /repos/grpc/third_party/protobuf > > RUN ./autogen.sh && ./configure --enable-static > > RUN make -j4 && make install && ldconfig > > WORKDIR /repos/grpc > > RUN make -j4 && make install && ldconfig > > > ... and the relevant cmake linking: > > target_link_libraries(my_app > > gRPC::grpc++ > > protobuf::libprotobuf) > > > ... and finally, the relevant dockerfile for the container where I'm > running my server: > FROM debian:stretch > > ADD my_app /my_app > > EXPOSE 50051 > > ENTRYPOINT ["/my_app", "0.0.0.0:50051"] > > > As I mentioned earlier, the gRPC server is reacting to the query and > doing... something. Logs are below. > > *Things I've tried:* > > - Changing OS in the docker container (so far I've tried Ubuntu and > Debian) > - Running my app in a known good container > (tobegit3hub/grpc-helloworld) (the helloworld app works, mine does not) > - Changing gRPC versions (I've tried 1.24.3 and 1.25.0) > - Building and linking protobuf separately (tried protobuf versions > 3.8.0 and 3.9.1) > - Manually linking JUST the _unsecure grpc libraries (this always > results in missing symbols, even if I link both libgrpc_unsecure and > libgrpc++_unsecure - it won't ever work until I also link in libgrpc) > - Endless variations of opening the ports in Docker. "docker run -p > 50051:50051 my_app", docker-compose "ports" configuration... > - Docker host networking (this results on no log messages from gRPC > whatsoever, as if when using host networking the client can't reach the > server) > - Using grpcurl instead of BloomRPC. *Interestingly, this gives an > error: "Failed to dial target host "0.0.0.0:50051 <http://0.0.0.0:50051>": > tls: first record does not look like a TLS handshake"* > > > > > *Below are the gRPC verbose logs:* > > journal-service_1 | I1115 15:52:45.888260872 10 > completion_queue.cc:960] grpc_completion_queue_next(cq=0x237aaa0, > deadline=gpr_timespec { tv_sec: 7601, tv_nsec: 444925114, clock_type: 0 }, > reserved=(nil)) > > journal-service_1 | I1115 15:52:47.684328068 9 > completion_queue.cc:960] grpc_completion_queue_next(cq=0x237aaa0, > deadline=gpr_timespec { tv_sec: 7603, tv_nsec: 240983924, clock_type: 0 }, > reserved=(nil)) > journal-service_1 | I1115 15:52:48.886953532 10 > tcp_server_posix.cc:242] SERVER_CONNECT: incoming connection: ipv4: > 172.18.0.1:55780 > journal-service_1 | D1115 15:52:48.887007693 10 tcp_posix.cc:1253] > cannot set inq fd=8 errno=92 > journal-service_1 | I1115 15:52:48.887062609 10 > chttp2_transport.cc:839] W:0x7f5440001f50 SERVER [ipv4:172.18.0.1:55780] > state IDLE -> WRITING [TRANSPORT_FLOW_CONTROL] > journal-service_1 | I1115 15:52:48.887070206 10 > chttp2_transport.cc:839] W:0x7f5440001f50 SERVER [ipv4:172.18.0.1:55780] > state WRITING -> WRITING+MORE [INITIAL_WRITE] > journal-service_1 | I1115 15:52:48.887074250 10 init.cc:164] > grpc_init(void) > journal-service_1 | I1115 15:52:48.887093265 10 > chttp2_transport.cc:1900] perform_transport_op[t=0x7f5440001f50]: > ON_CONNECTIVITY_STATE_CHANGE:p=0x7f5440003cf0:from=IDLE > SET_ACCEPT_STREAM:0x7feb10(0x7f5440003c88,...) > journal-service_1 | I1115 15:52:48.887100719 10 > chttp2_transport.cc:1900] perform_transport_op[t=0x7f5440001f50]: > ON_CONNECTIVITY_STATE_CHANGE:p=0x7f5440003cf0:from=READY > journal-service_1 | I1115 15:52:48.887104135 10 tcp_posix.cc:265] > TCP:0x7f54400018d0 notify_on_read > journal-service_1 | I1115 15:52:48.887109550 10 writing.cc:116] > SERVER: Ping sent [ipv4:172.18.0.1:55780]: 2/2 > journal-service_1 | I1115 15:52:48.887113039 10 > chttp2_transport.cc:839] W:0x7f5440001f50 SERVER [ipv4:172.18.0.1:55780] > state WRITING+MORE -> WRITING [begin write in current thread] > journal-service_1 | I1115 15:52:48.887123552 10 tcp_posix.cc:1058] > WRITE 0x7f54400018d0 (peer=ipv4:172.18.0.1:55780) > journal-service_1 | D1115 15:52:48.887157759 10 tcp_posix.cc:1062] > DATA: 00 00 18 04 00 00 00 00 00 00 04 00 40 00 00 00 05 00 40 00 00 > 00 06 00 00 20 00 fe 03 00 00 00 01 '............@.....@...... .......' > journal-service_1 | I1115 15:52:48.887162534 10 tcp_posix.cc:1058] > WRITE 0x7f54400018d0 (peer=ipv4:172.18.0.1:55780) > journal-service_1 | D1115 15:52:48.887165687 10 tcp_posix.cc:1062] > DATA: 00 00 04 08 00 00 00 00 00 00 3f 00 01 00 00 08 06 00 00 00 00 > 00 00 '..........?............' > journal-service_1 | I1115 15:52:48.887168113 10 tcp_posix.cc:1058] > WRITE 0x7f54400018d0 (peer=ipv4:172.18.0.1:55780) > journal-service_1 | D1115 15:52:48.887170653 10 tcp_posix.cc:1062] > DATA: 00 00 00 00 00 00 00 '.......' > journal-service_1 | I1115 15:52:48.887276538 10 tcp_posix.cc:1096] > write: "No Error" > journal-service_1 | I1115 15:52:48.887287956 10 > chttp2_transport.cc:2660] ipv4:172.18.0.1:55780: Start BDP ping err="No > Error" > journal-service_1 | I1115 15:52:48.887293261 10 > chttp2_transport.cc:839] W:0x7f5440001f50 SERVER [ipv4:172.18.0.1:55780] > state WRITING -> IDLE [finish writing] > journal-service_1 | I1115 15:52:48.887551243 10 tcp_posix.cc:605] > TCP:0x7f54400018d0 got_read: "No Error" > journal-service_1 | I1115 15:52:48.887559234 10 tcp_posix.cc:590] > TCP:0x7f54400018d0 alloc_slices > journal-service_1 | I1115 15:52:48.887571028 10 tcp_posix.cc:571] > TCP:0x7f54400018d0 read_allocation_done: "No Error" > journal-service_1 | I1115 15:52:48.887658860 10 tcp_posix.cc:401] > TCP:0x7f54400018d0 call_cb 0x7f5440002090 0x83ca50:0x7f5440001f50 > journal-service_1 | I1115 15:52:48.887669585 10 tcp_posix.cc:404] > READ 0x7f54400018d0 (peer=ipv4:172.18.0.1:55780) error="No Error" > journal-service_1 | D1115 15:52:48.887700032 10 tcp_posix.cc:410] > DATA: 50 52 49 20 2a 20 48 54 54 50 2f 32 2e 30 0d 0a 0d 0a 53 4d > 0d 0a 0d 0a 00 00 24 04 00 00 00 00 00 00 02 00 00 00 00 00 03 00 00 00 00 > 00 04 00 40 00 00 00 05 00 40 00 00 00 06 00 00 20 00 fe 03 00 00 00 01 00 > 00 04 08 00 00 00 00 00 00 3f 00 01 00 00 08 06 00 00 00 00 00 00 00 00 00 > 00 00 00 00 00 01 05 01 04 00 00 00 01 86 83 40 0a 3a 61 75 74 68 6f 72 69 > 74 79 0d 30 2e 30 2e 30 2e 30 3a 35 30 30 35 31 40 05 3a 70 61 74 68 2b 2f > 73 65 72 76 69 63 65 2e 6a 6f 75 72 6e 61 6c 2e 4a 6f 75 72 6e 61 6c 53 65 > 72 76 69 63 65 2f 47 65 74 53 6e 61 70 73 68 6f 74 40 02 74 65 08 74 72 61 > 69 6c 65 72 73 40 0c 63 6f 6e 74 65 6e 74 2d 74 79 70 65 10 61 70 70 6c 69 > 63 61 74 69 6f 6e 2f 67 72 70 63 40 0a 75 73 65 72 2d 61 67 65 6e 74 32 67 > 72 70 63 2d 6e 6f 64 65 2f 31 2e 31 37 2e 30 20 67 72 70 63 2d 63 2f 37 2e > 30 2e 30 20 28 6f 73 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 40 > 14 67 72 70 63 2d 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 15 69 64 65 > 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 40 0f 61 63 63 65 70 > 74 2d 65 6e 63 6f 64 69 6e 67 0d 69 64 65 6e 74 69 74 79 2c 67 7a 69 70 00 > 00 04 08 00 00 00 00 01 00 00 00 05 00 00 1f 00 01 00 00 00 01 00 00 00 00 > 1a 0a 06 0a 04 72 75 6e 32 12 10 0a 02 08 01 12 06 08 c4 e0 86 ee 05 1a 02 > 08 01 00 00 04 08 00 00 00 00 00 00 00 00 05 'PRI * > HTTP/2.0....SM......$.....................@.....@...... > .................?..............................@.:authority.0.0.0.0:50051@.:path+/service.journal.JournalService/[email protected]@.content-type.application/[email protected]/1.17.0 > > grpc-c/7.0.0 (osx; chttp2; > gizmo)@.grpc-accept-encoding.identity,deflate,[email protected],gzip...............................run2...............................' > journal-service_1 | I1115 15:52:48.887711722 10 > frame_settings.cc:230] CHTTP2:SVR:ipv4:172.18.0.1:55780: got setting > ENABLE_PUSH = 0 > journal-service_1 | I1115 15:52:48.887715289 10 > frame_settings.cc:230] CHTTP2:SVR:ipv4:172.18.0.1:55780: got setting > MAX_CONCURRENT_STREAMS = 0 > journal-service_1 | I1115 15:52:48.887718017 10 > frame_settings.cc:223] 0x7f5440001f50[svr] adding 4128769 for > initial_window change > journal-service_1 | I1115 15:52:48.887720656 10 > frame_settings.cc:230] CHTTP2:SVR:ipv4:172.18.0.1:55780: got setting > INITIAL_WINDOW_SIZE = 4194304 > journal-service_1 | I1115 15:52:48.887723161 10 > frame_settings.cc:230] CHTTP2:SVR:ipv4:172.18.0.1:55780: got setting > MAX_FRAME_SIZE = 4194304 > journal-service_1 | I1115 15:52:48.887725675 10 > frame_settings.cc:230] CHTTP2:SVR:ipv4:172.18.0.1:55780: got setting > MAX_HEADER_LIST_SIZE = 8192 > journal-service_1 | I1115 15:52:48.887728010 10 > frame_settings.cc:230] CHTTP2:SVR:ipv4:172.18.0.1:55780: got setting > GRPC_ALLOW_TRUE_BINARY_METADATA = 1 > journal-service_1 | I1115 15:52:48.887731968 10 > chttp2_transport.cc:839] W:0x7f5440001f50 SERVER [ipv4:172.18.0.1:55780] > state IDLE -> WRITING [PING_RESPONSE] > journal-service_1 | I1115 15:52:48.887743241 10 call.cc:1566] > ops[0]: RECV_INITIAL_METADATA ptr=0x7f5440006b38 > journal-service_1 | I1115 15:52:48.887747725 10 parsing.cc:681] > parsing initial_metadata > journal-service_1 | I1115 15:52:48.887752449 10 parsing.cc:430] > HTTP:1:HDR:SVR: :scheme: 68 74 74 70 'http' > journal-service_1 | I1115 15:52:48.887755845 10 parsing.cc:430] > HTTP:1:HDR:SVR: :method: 50 4f 53 54 'POST' > journal-service_1 | I1115 15:52:48.887761879 10 parsing.cc:430] > HTTP:1:HDR:SVR: :authority: 30 2e 30 2e 30 2e 30 3a 35 30 30 35 31 ' > 0.0.0.0:50051' > journal-service_1 | I1115 15:52:48.887766754 10 parsing.cc:430] > HTTP:1:HDR:SVR: :path: 2f 73 65 72 76 69 63 65 2e 6a 6f 75 72 6e 61 > 6c 2e 4a 6f 75 72 6e 61 6c 53 65 72 76 69 63 65 2f 47 65 74 53 6e 61 70 73 > 68 6f 74 '/service.journal.JournalService/GetSnapshot' > journal-service_1 | I1115 15:52:48.887770751 10 parsing.cc:430] > HTTP:1:HDR:SVR: te: 74 72 61 69 6c 65 72 73 'trailers' > journal-service_1 | I1115 15:52:48.887774505 10 parsing.cc:430] > HTTP:1:HDR:SVR: content-type: 61 70 70 6c 69 63 61 74 69 6f 6e 2f > 67 72 70 63 'application/grpc' > journal-service_1 | I1115 15:52:48.887780236 10 parsing.cc:430] > HTTP:1:HDR:SVR: user-agent: 67 72 70 63 2d 6e 6f 64 65 2f 31 2e 31 > 37 2e 30 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6f 73 78 3b 20 63 68 > 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-node/1.17.0 grpc-c/7.0.0 (osx; > chttp2; gizmo)' > journal-service_1 | I1115 15:52:48.887784312 10 parsing.cc:430] > HTTP:1:HDR:SVR: grpc-accept-encoding: 69 64 65 6e 74 69 74 79 2c 64 > 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip' > journal-service_1 | I1115 15:52:48.887787801 10 parsing.cc:430] > HTTP:1:HDR:SVR: accept-encoding: 69 64 65 6e 74 69 74 79 2c 67 7a > 69 70 'identity,gzip' > journal-service_1 | I1115 15:52:48.887794660 10 > chttp2_transport.cc:1733] perform_stream_op[s=0x7f5440007608]: > RECV_INITIAL_METADATA > journal-service_1 | I1115 15:52:48.887797899 10 tcp_posix.cc:605] > TCP:0x7f54400018d0 got_read: "No Error" > journal-service_1 | I1115 15:52:48.887800536 10 tcp_posix.cc:596] > TCP:0x7f54400018d0 do_read > journal-service_1 | I1115 15:52:48.887804697 10 tcp_posix.cc:265] > TCP:0x7f54400018d0 notify_on_read > journal-service_1 | I1115 15:52:48.887809455 10 > chttp2_transport.cc:1435] perform_stream_op_locked: > RECV_INITIAL_METADATA; on_complete = (nil) > journal-service_1 | I1115 15:52:48.887815426 10 call.cc:1566] > ops[0]: RECV_MESSAGE ptr=0x7f5440006b58 > journal-service_1 | I1115 15:52:48.887819081 10 > chttp2_transport.cc:1733] perform_stream_op[s=0x7f5440007608]: > RECV_MESSAGE > journal-service_1 | I1115 15:52:48.887822124 10 > chttp2_transport.cc:1435] perform_stream_op_locked: RECV_MESSAGE; > on_complete = (nil) > journal-service_1 | I1115 15:52:48.887849739 10 > completion_queue.cc:682] cq_end_op_for_next(cq=0x237aaa0, tag=0x237b960, > error="No Error", done=0x7fc8e0, done_arg=0x7f54480008e0, > storage=0x7f5448000918) > journal-service_1 | I1115 15:52:48.887862750 10 > chttp2_transport.cc:839] W:0x7f5440001f50 SERVER [ipv4:172.18.0.1:55780] > state WRITING -> WRITING [begin write in current thread] > journal-service_1 | I1115 15:52:48.887882260 10 tcp_posix.cc:1058] > WRITE 0x7f54400018d0 (peer=ipv4:172.18.0.1:55780) > journal-service_1 | D1115 15:52:48.887891216 10 tcp_posix.cc:1062] > DATA: 00 00 08 06 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 04 > 01 00 '.......................' > journal-service_1 | I1115 15:52:48.887895779 10 tcp_posix.cc:1058] > WRITE 0x7f54400018d0 (peer=ipv4:172.18.0.1:55780) > journal-service_1 | D1115 15:52:48.887900032 10 tcp_posix.cc:1062] > DATA: 00 00 00 00 00 04 08 00 00 00 00 00 00 00 00 1f > '................' > journal-service_1 | I1115 15:52:48.887927279 10 tcp_posix.cc:1096] > write: "No Error" > journal-service_1 | I1115 15:52:48.887938364 10 > chttp2_transport.cc:839] W:0x7f5440001f50 SERVER [ipv4:172.18.0.1:55780] > state WRITING -> IDLE [finish writing] > journal-service_1 | I1115 15:52:48.887978281 10 > completion_queue.cc:1060] RETURN_EVENT[0x237aaa0]: OP_COMPLETE: > tag:0x237b960 OK > journal-service_1 | I1115 15:52:48.888025273 10 > completion_queue.cc:504] > grpc_completion_queue_create_internal(completion_type=1, polling_type=0) > journal-service_1 | I1115 15:52:48.888216980 10 server.cc:1525] > grpc_server_request_registered_call(server=0x237b300, > rmp=0x237ba70, call=0x237b980, deadline=0x237b990, > initial_metadata=0x237b9a0, optional_payload=0x237b9b8, > cq_bound_to_call=0x7f5440001bc0, cq_for_notification=0x237aaa0, > tag=0x237b960) > journal-service_1 | I1115 15:52:48.888257792 10 call.cc:1967] > grpc_call_start_batch(call=0x7f54400060a0, ops=0x7f544d719af0, > nops=1, tag=0x7f5440008550, reserved=(nil)) > journal-service_1 | I1115 15:52:48.888024194 9 tcp_posix.cc:605] > TCP:0x7f54400018d0 got_read: "No Error" > journal-service_1 | I1115 15:52:48.888314290 9 tcp_posix.cc:596] > TCP:0x7f54400018d0 do_read > journal-service_1 | I1115 15:52:48.888329702 9 tcp_posix.cc:401] > TCP:0x7f54400018d0 call_cb 0x7f5440002090 0x83ca50:0x7f5440001f50 > journal-service_1 | I1115 15:52:48.888335434 9 tcp_posix.cc:404] > READ 0x7f54400018d0 (peer=ipv4:172.18.0.1:55780) error="No Error" > journal-service_1 | I1115 15:52:48.888272266 10 call.cc:1566] > ops[0]: RECV_CLOSE_ON_SERVER cancelled=0x7f54400085dc > journal-service_1 | I1115 15:52:48.888373084 10 > chttp2_transport.cc:1733] perform_stream_op[s=0x7f5440007608]: > RECV_TRAILING_METADATA > journal-service_1 | I1115 15:52:48.888455399 10 > chttp2_transport.cc:1435] perform_stream_op_locked: > RECV_TRAILING_METADATA; on_complete = (nil) > journal-service_1 | D1115 15:52:48.888342155 9 tcp_posix.cc:410] > DATA: 00 00 08 06 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 > 04 01 00 00 00 00 '..........................' > journal-service_1 | I1115 15:52:48.888577114 9 tcp_posix.cc:605] > TCP:0x7f54400018d0 got_read: "No Error" > journal-service_1 | I1115 15:52:48.888583848 9 tcp_posix.cc:596] > TCP:0x7f54400018d0 do_read > journal-service_1 | I1115 15:52:48.888590804 9 tcp_posix.cc:265] > TCP:0x7f54400018d0 notify_on_read > journal-service_1 | I1115 15:52:48.888594508 9 > chttp2_transport.cc:2676] ipv4:172.18.0.1:55780: Complete BDP ping > err="No Error" > journal-service_1 | I found data for run2 in 1 directories that I own. > journal-service_1 | I1115 15:52:48.894985433 10 call.cc:1967] > grpc_call_start_batch(call=0x7f54400060a0, ops=0x7f544d719680, > nops=2, tag=0x7f544d7199e0, reserved=(nil)) > journal-service_1 | I1115 15:52:48.895006636 10 call.cc:1566] > ops[0]: SEND_INITIAL_METADATA(nil) > journal-service_1 | I1115 15:52:48.895014011 10 call.cc:1566] > ops[1]: SEND_STATUS_FROM_SERVER status=2 details=Unexpected error > in RPC handling(nil) > journal-service_1 | I1115 15:52:48.895077932 10 > chttp2_transport.cc:1733] perform_stream_op[s=0x7f5440007608]: > SEND_INITIAL_METADATA{key=3a 73 74 61 74 75 73 ':status' value=32 30 30 > '200', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 > 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=67 72 70 > 63 2d 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'grpc-accept-encoding' > value=69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 > 'identity,deflate,gzip', key=61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 > 'accept-encoding' value=69 64 65 6e 74 69 74 79 2c 67 7a 69 70 > 'identity,gzip'} SEND_TRAILING_METADATA{key=67 72 70 63 2d 73 74 61 74 75 > 73 'grpc-status' value=32 '2', key=67 72 70 63 2d 6d 65 73 73 61 67 65 > 'grpc-message' value=55 6e 65 78 70 65 63 74 65 64 20 65 72 72 6f 72 20 69 > 6e 20 52 50 43 20 68 61 6e 64 6c 69 6e 67 'Unexpected error in RPC > handling'} > journal-service_1 | I1115 15:52:48.895119707 10 > chttp2_transport.cc:1435] perform_stream_op_locked: > SEND_INITIAL_METADATA{key=3a 73 74 61 74 75 73 ':status' value=32 30 30 > '200', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 > 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=67 72 70 > 63 2d 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'grpc-accept-encoding' > value=69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 > 'identity,deflate,gzip', key=61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 > 'accept-encoding' value=69 64 65 6e 74 69 74 79 2c 67 7a 69 70 > 'identity,gzip'} SEND_TRAILING_METADATA{key=67 72 70 63 2d 73 74 61 74 75 > 73 'grpc-status' value=32 '2', key=67 72 70 63 2d 6d 65 73 73 61 67 65 > 'grpc-message' value=55 6e 65 78 70 65 63 74 65 64 20 65 72 72 6f 72 20 69 > 6e 20 52 50 43 20 68 61 6e 64 6c 69 6e 67 'Unexpected error in RPC > handling'}; on_complete = 0x7f54400073c8 > journal-service_1 | I1115 15:52:48.895131125 10 > chttp2_transport.cc:1411] HTTP:1:HDR:SVR: :status: 200 > journal-service_1 | I1115 15:52:48.895134700 10 > chttp2_transport.cc:1411] HTTP:1:HDR:SVR: content-type: application/grpc > journal-service_1 | I1115 15:52:48.895137310 10 > chttp2_transport.cc:1411] HTTP:1:HDR:SVR: grpc-accept-encoding: > identity,deflate,gzip > journal-service_1 | I1115 15:52:48.895147091 10 > chttp2_transport.cc:1411] HTTP:1:HDR:SVR: accept-encoding: identity,gzip > journal-service_1 | I1115 15:52:48.895153883 10 > chttp2_transport.cc:1411] HTTP:1:TRL:SVR: grpc-status: 2 > journal-service_1 | I1115 15:52:48.895158938 10 > chttp2_transport.cc:1411] HTTP:1:TRL:SVR: grpc-message: Unexpected error > in RPC handling > journal-service_1 | I1115 15:52:48.895205876 10 > chttp2_transport.cc:839] W:0x7f5440001f50 SERVER [ipv4:172.18.0.1:55780] > state IDLE -> WRITING [SEND_INITIAL_METADATA] > journal-service_1 | I1115 15:52:48.895218008 10 > chttp2_transport.cc:839] W:0x7f5440001f50 SERVER [ipv4:172.18.0.1:55780] > state WRITING -> WRITING+MORE [SEND_TRAILING_METADATA] > journal-service_1 | I1115 15:52:48.895227726 10 > chttp2_transport.cc:1284] complete_closure_step: t=0x7f5440001f50 > 0x7f54400073c8 refs=2 flags=0x0001 desc=op->on_complete err="No Error" > write_state=WRITING+MORE > journal-service_1 | I1115 15:52:48.895240378 10 writing.cc:434] > W:0x7f5440001f50 SERVER[1] im-(sent,send)=(0,1) announce=0 > journal-service_1 | I1115 15:52:48.895247361 10 writing.cc:590] > not sending initial_metadata (Trailers-Only) > journal-service_1 | I1115 15:52:48.895260851 10 > chttp2_transport.cc:1284] complete_closure_step: t=0x7f5440001f50 > 0x7f54400073c8 refs=1 flags=0x0001 desc=send_initial_metadata_finished > err="No Error" write_state=WRITING+MORE > journal-service_1 | I1115 15:52:48.895265551 10 writing.cc:557] > sending trailing_metadata > journal-service_1 | I1115 15:52:48.895270278 10 > hpack_encoder.cc:486] Encode: 'content-type: application/grpc', > elem_interned=1 [1], k_interned=1, v_interned=1 > journal-service_1 | I1115 15:52:48.895275797 10 > hpack_encoder.cc:486] Encode: 'grpc-status: 2', elem_interned=1 [1], > k_interned=1, v_interned=1 > journal-service_1 | I1115 15:52:48.895280774 10 > hpack_encoder.cc:486] Encode: 'grpc-message: Unexpected error in RPC > handling', elem_interned=0 [2], k_interned=1, v_interned=0 > journal-service_1 | I1115 15:52:48.895287052 10 > chttp2_transport.cc:1284] complete_closure_step: t=0x7f5440001f50 > 0x7f54400073c8 refs=0 flags=0x0001 desc=send_trailing_metadata_finished > err="No Error" write_state=WRITING+MORE > journal-service_1 | I1115 15:52:48.895294233 10 > chttp2_transport.cc:839] W:0x7f5440001f50 SERVER [ipv4:172.18.0.1:55780] > state WRITING+MORE -> WRITING [begin write in current thread] > journal-service_1 | I1115 15:52:48.895298023 10 tcp_posix.cc:1058] > WRITE 0x7f54400018d0 (peer=ipv4:172.18.0.1:55780) > journal-service_1 | D1115 15:52:48.895301616 10 tcp_posix.cc:1062] > DATA: 00 00 5e 01 05 00 00 00 01 88 40 0c '..^.......@.' > journal-service_1 | I1115 15:52:48.895304811 10 tcp_posix.cc:1058] > WRITE 0x7f54400018d0 (peer=ipv4:172.18.0.1:55780) > journal-service_1 | D1115 15:52:48.895308809 10 tcp_posix.cc:1062] > DATA: 63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' > journal-service_1 | I1115 15:52:48.895312357 10 tcp_posix.cc:1058] > WRITE 0x7f54400018d0 (peer=ipv4:172.18.0.1:55780) > journal-service_1 | D1115 15:52:48.895316110 10 tcp_posix.cc:1062] > DATA: 10 '.' > journal-service_1 | I1115 15:52:48.895319685 10 tcp_posix.cc:1058] > WRITE 0x7f54400018d0 (peer=ipv4:172.18.0.1:55780) > journal-service_1 | D1115 15:52:48.895323521 10 tcp_posix.cc:1062] > DATA: 61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 > 'application/grpc' > journal-service_1 | I1115 15:52:48.895338694 10 tcp_posix.cc:1058] > WRITE 0x7f54400018d0 (peer=ipv4:172.18.0.1:55780) > journal-service_1 | D1115 15:52:48.895370800 10 tcp_posix.cc:1062] > DATA: 40 0b '@.' > journal-service_1 | I1115 15:52:48.895378830 10 tcp_posix.cc:1058] > WRITE 0x7f54400018d0 (peer=ipv4:172.18.0.1:55780) > journal-service_1 | D1115 15:52:48.895386495 10 tcp_posix.cc:1062] > DATA: 67 72 70 63 2d 73 74 61 74 75 73 'grpc-status' > journal-service_1 | I1115 15:52:48.895391926 10 tcp_posix.cc:1058] > WRITE 0x7f54400018d0 (peer=ipv4:172.18.0.1:55780) > journal-service_1 | D1115 15:52:48.895395862 10 tcp_posix.cc:1062] > DATA: 01 '.' > journal-service_1 | I1115 15:52:48.895399384 10 tcp_posix.cc:1058] > WRITE 0x7f54400018d0 (peer=ipv4:172.18.0.1:55780) > journal-service_1 | D1115 15:52:48.895401963 10 tcp_posix.cc:1062] > DATA: 32 '2' > journal-service_1 | I1115 15:52:48.895404244 10 tcp_posix.cc:1058] > WRITE 0x7f54400018d0 (peer=ipv4:172.18.0.1:55780) > journal-service_1 | D1115 15:52:48.895406731 10 tcp_posix.cc:1062] > DATA: 40 0c '@.' > journal-service_1 | I1115 15:52:48.895436701 10 tcp_posix.cc:1058] > WRITE 0x7f54400018d0 (peer=ipv4:172.18.0.1:55780) > journal-service_1 | D1115 15:52:48.895476220 10 tcp_posix.cc:1062] > DATA: 67 72 70 63 2d 6d 65 73 73 61 67 65 'grpc-message' > journal-service_1 | I1115 15:52:48.895483121 10 tcp_posix.cc:1058] > WRITE 0x7f54400018d0 (peer=ipv4:172.18.0.1:55780) > journal-service_1 | D1115 15:52:48.895487321 10 tcp_posix.cc:1062] > DATA: 20 ' ' > journal-service_1 | I1115 15:52:48.895490852 10 tcp_posix.cc:1058] > WRITE 0x7f54400018d0 (peer=ipv4:172.18.0.1:55780) > journal-service_1 | D1115 15:52:48.895495475 10 tcp_posix.cc:1062] > DATA: 55 6e 65 78 70 65 63 74 65 64 20 65 72 72 6f 72 20 69 6e 20 52 > 50 43 20 68 61 6e 64 6c 69 6e 67 'Unexpected error in RPC handling' > journal-service_1 | I1115 15:52:48.895597061 10 tcp_posix.cc:1096] > write: "No Error" > journal-service_1 | I1115 15:52:48.895610227 10 > completion_queue.cc:764] cq_end_op_for_pluck(cq=0x7f54480044c0, > tag=0x7f5440008550, error="No Error", done=0x7f58b0, > done_arg=0x7f54400086f0, storage=0x7f5440008740) > journal-service_1 | I1115 15:52:48.895619122 10 > chttp2_transport.cc:839] W:0x7f5440001f50 SERVER [ipv4:172.18.0.1:55780] > state WRITING -> IDLE [finish writing] > journal-service_1 | I1115 15:52:48.895627333 10 > completion_queue.cc:764] cq_end_op_for_pluck(cq=0x7f54480044c0, > tag=0x7f544d7199e0, error="No Error", done=0x7f58b0, > done_arg=0x7f54400087d0, storage=0x7f5440008820) > journal-service_1 | I1115 15:52:48.895639296 10 > completion_queue.cc:1296] RETURN_EVENT[0x7f54480044c0]: OP_COMPLETE: > tag:0x7f544d7199e0 OK > journal-service_1 | I1115 15:52:48.895653047 10 > completion_queue.cc:1398] > grpc_completion_queue_shutdown(cq=0x7f54480044c0) > journal-service_1 | I1115 15:52:48.895662468 10 > completion_queue.cc:1296] RETURN_EVENT[0x7f54480044c0]: OP_COMPLETE: > tag:0x7f5440008550 OK > journal-service_1 | I1115 15:52:48.895670097 10 > completion_queue.cc:1296] RETURN_EVENT[0x7f54480044c0]: QUEUE_SHUTDOWN > journal-service_1 | I1115 15:52:48.895675991 10 > metadata_array.cc:34] > grpc_metadata_array_destroy(array=0x7f54400091e0) > journal-service_1 | I1115 15:52:48.895683204 10 call.cc:573] > grpc_call_unref(c=0x7f54400060a0) > journal-service_1 | I1115 15:52:48.895706621 10 > metadata_array.cc:34] > grpc_metadata_array_destroy(array=0x7f5440006b38) > journal-service_1 | I1115 15:52:48.895724730 10 > metadata_array.cc:34] > grpc_metadata_array_destroy(array=0x7f54400091e0) > > > > journal-service_1 | I1115 15:52:48.895733132 10 > completion_queue.cc:1404] grpc_completion_queue_destroy(cq=0x7f54480044c0) > journal-service_1 | I1115 15:52:48.895737667 10 > completion_queue.cc:1398] > grpc_completion_queue_shutdown(cq=0x7f54480044c0) > journal-service_1 | I1115 15:52:48.895747282 10 > completion_queue.cc:960] grpc_completion_queue_next(cq=0x237aaa0, > deadline=gpr_timespec { tv_sec: 7604, tv_nsec: 452416786, clock_type: 0 }, > reserved=(nil)) > journal-service_1 | I1115 15:52:48.909412760 9 tcp_posix.cc:605] > TCP:0x7f54400018d0 got_read: "No Error" > journal-service_1 | I1115 15:52:48.909466978 9 tcp_posix.cc:596] > TCP:0x7f54400018d0 do_read > journal-service_1 | I1115 15:52:48.909481404 9 tcp_posix.cc:401] > TCP:0x7f54400018d0 call_cb 0x7f5440002090 0x83ca50:0x7f5440001f50 > journal-service_1 | I1115 15:52:48.909492130 9 tcp_posix.cc:404] > READ 0x7f54400018d0 (peer=ipv4:172.18.0.1:55780) > error={"created":"@1573833168.909479700","description":"Socket > closed","fd":8,"file":"src/core/lib/iomgr/tcp_posix.cc","file_line":502,"grpc_status":14,"target_address":"ipv4: > 172.18.0.1:55780"} > journal-service_1 | I1115 15:52:48.909497666 9 > chttp2_transport.cc:2866] transport 0x7f5440001f50 set > connectivity_state=4 > journal-service_1 | I1115 15:52:48.909584127 9 > chttp2_transport.cc:1900] perform_transport_op[t=0x7f5440001f50]: > SET_ACCEPT_STREAM:(nil)((nil),...) > journal-service_1 | I1115 15:52:48.909612733 9 tcp_posix.cc:854] > TCP:0x7f54400018d0 got_error: > {"created":"@1573833168.909578991","description":"FD > Shutdown","file":"src/core/lib/iomgr/lockfree_event.cc","file_line":194,"referenced_errors":[{"created":"@1573833168.909495939","description":"Endpoint > > read > failed","file":"src/core/ext/transport/chttp2/transport/chttp2_transport.cc","file_line":2559,"occurred_during_write":0,"referenced_errors":[{"created":"@1573833168.909479700","description":"Socket > > closed","fd":8,"file":"src/core/lib/iomgr/tcp_posix.cc","file_line":502,"grpc_status":14,"target_address":"ipv4: > 172.18.0.1:55780"}]}]} > journal-service_1 | I1115 15:52:48.909624929 9 init.cc:211] > grpc_shutdown(void) > journal-service_1 | I1115 15:52:57.689572394 9 > completion_queue.cc:960] grpc_completion_queue_next(cq=0x237aaa0, > deadline=gpr_timespec { tv_sec: 7613, tv_nsec: 246234878, clock_type: 0 }, > reserved=(nil)) > -- 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 [email protected]. To view this discussion on the web visit https://groups.google.com/d/msgid/grpc-io/b3444901-cfbd-4559-9cc1-b80c6f2d943e%40googlegroups.com.
