Grpc client blocked after system time change v1.60.0

67 views
Skip to first unread message

eby f

unread,
Mar 19, 2025, 11:59:44 PM3/19/25
to grpc.io

What version of gRPC and what language are you using?
C++ 1.41.0 / Java 1.60.2

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

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

I currently have two processes on the same windows PC, one of which is a java process (grpc v1.60.2) and the other is a C++ process (grpc v1.41.0). Each of the two processes has a grpc Server and Client. The following Heartbeat interfaces are defined between them. They call each other every 2 seconds. The timeout of the rpc interface is 2 seconds. If any process cannot call the other process within a period of time, some corresponding abnormal actions will be triggered


service Heartbeat { rpc Heartbeat(EmptyMessage) returns (HeartBeatReturnMessage) {} } message EmptyMessage {} message HeartBeatReturnMessage { bool Status = 1; }

Recently, my PC occasionally needs to modify the system time (the offset is about one minute before or after the current time), and it is found that sometimes the interface call is blocked, sometimes more than 10 seconds, so it goes to its own abnormal code.

then I found some similar problem like
gRPC is blocking after system time changes
then I update the C++ grpc version to v1.60.0,but it not worked

After opening the grpc log, the following problems are found:

eby f

unread,
Mar 20, 2025, 11:00:31 AM3/20/25
to grpc.io
```
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:338][GRPCLOG][INFO]INCOMING[000001653D3390D0]: RST_STREAM len:4 id:0x000005e9
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:911][GRPCLOG][DEBUG]INCOMING[000001653D3390D0;000001653D4493F0]: Parse 4b last frame fragment with rst_stream
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\frame_rst_stream.cc:115][GRPCLOG][INFO][chttp2 transport=000001653D3390D0 stream=000001653D4493F0] received RST_STREAM(reason=8)
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2428][GRPCLOG][DEBUG]MARK_STREAM_CLOSED: t=000001653D3390D0 s=000001653D4493F0(id=1513) read+write [UNKNOWN:RST_STREAM {created_time:"2025-03-14T07:00:00.403807+00:00", grpc_message:"Received RST_STREAM with error code 8", http2_error:8}]
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=0 s=000001653D4493F0 closure=0000000000000000 read_closed=1 write_closed=1 0
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=0 s=000001653D4493F0 closure=0000000000000000 read_closed=1 write_closed=1 0
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:3108][GRPCLOG][INFO]ipv4:127.0.0.1:28015: Keepalive ping cancelled. Resetting timer.
[2025-03-14 15:00:00.403][37884][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1747][GRPCLOG][INFO]perform_stream_op[s=000001653D4493F0; op=000001653D37B978]:  CANCEL:UNKNOWN:Deadline Exceeded {grpc_status:4, created_time:"2025-03-14T07:00:00.403807+00:00"}
[2025-03-14 15:00:00.403][37884][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1747][GRPCLOG][INFO]perform_stream_op[s=000001653D4493F0; op=000001653D37C678]:  CANCEL:UNKNOWN:Deadline Exceeded {grpc_status:4, created_time:"2025-03-14T07:00:00.403807+00:00"}
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1475][GRPCLOG][INFO]perform_stream_op_locked[s=000001653D4493F0; op=000001653D37B978]:  CANCEL:UNKNOWN:Deadline Exceeded {grpc_status:4, created_time:"2025-03-14T07:00:00.403807+00:00"}; on_complete = 000001653D43DF50
[2025-03-14 15:00:00.403][37884][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1747][GRPCLOG][INFO]perform_stream_op[s=000001653D4493F0; op=000001653D37C578]:  CANCEL:UNKNOWN:Deadline Exceeded {grpc_status:4, created_time:"2025-03-14T07:00:00.403807+00:00"}
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2428][GRPCLOG][DEBUG]MARK_STREAM_CLOSED: t=000001653D3390D0 s=000001653D4493F0(id=1513) read+write [UNKNOWN:Deadline Exceeded {grpc_status:4, created_time:"2025-03-14T07:00:00.403807+00:00"}]
[2025-03-14 15:00:00.403][37884][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1747][GRPCLOG][INFO]perform_stream_op[s=000001653D4493F0; op=000001653D37BD78]:  CANCEL:UNKNOWN:Deadline Exceeded {grpc_status:4, created_time:"2025-03-14T07:00:00.403807+00:00"}
[2025-03-14 15:00:00.403][37884][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1747][GRPCLOG][INFO]perform_stream_op[s=000001653D4493F0; op=000001653D37C078]:  CANCEL:UNKNOWN:Deadline Exceeded {grpc_status:4, created_time:"2025-03-14T07:00:00.403807+00:00"}
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=0 s=000001653D4493F0 closure=0000000000000000 read_closed=1 write_closed=1 0
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=0 s=000001653D4493F0 closure=0000000000000000 read_closed=1 write_closed=1 0
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1397][GRPCLOG][INFO]complete_closure_step: t=000001653D3390D0 000001653D43DF50 refs=0 flags=0x0000 desc=op->on_complete err=OK write_state=IDLE whence=(null):-1
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1475][GRPCLOG][INFO]perform_stream_op_locked[s=000001653D4493F0; op=000001653D37C678]:  CANCEL:UNKNOWN:Deadline Exceeded {grpc_status:4, created_time:"2025-03-14T07:00:00.403807+00:00"}; on_complete = 000001653D43DF90
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2428][GRPCLOG][DEBUG]MARK_STREAM_CLOSED: t=000001653D3390D0 s=000001653D4493F0(id=1513) read+write [UNKNOWN:Deadline Exceeded {grpc_status:4, created_time:"2025-03-14T07:00:00.403807+00:00"}]
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=0 s=000001653D4493F0 closure=0000000000000000 read_closed=1 write_closed=1 0
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=0 s=000001653D4493F0 closure=0000000000000000 read_closed=1 write_closed=1 0
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1397][GRPCLOG][INFO]complete_closure_step: t=000001653D3390D0 000001653D43DF90 refs=0 flags=0x0000 desc=op->on_complete err=OK write_state=IDLE whence=(null):-1
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1475][GRPCLOG][INFO]perform_stream_op_locked[s=000001653D4493F0; op=000001653D37C578]:  CANCEL:UNKNOWN:Deadline Exceeded {grpc_status:4, created_time:"2025-03-14T07:00:00.403807+00:00"}; on_complete = 000001653D43E710
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2428][GRPCLOG][DEBUG]MARK_STREAM_CLOSED: t=000001653D3390D0 s=000001653D4493F0(id=1513) read+write [UNKNOWN:Deadline Exceeded {grpc_status:4, created_time:"2025-03-14T07:00:00.403807+00:00"}]
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=0 s=000001653D4493F0 closure=0000000000000000 read_closed=1 write_closed=1 0
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=0 s=000001653D4493F0 closure=0000000000000000 read_closed=1 write_closed=1 0
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1397][GRPCLOG][INFO]complete_closure_step: t=000001653D3390D0 000001653D43E710 refs=0 flags=0x0000 desc=op->on_complete err=OK write_state=IDLE whence=(null):-1
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1475][GRPCLOG][INFO]perform_stream_op_locked[s=000001653D4493F0; op=000001653D37BD78]:  CANCEL:UNKNOWN:Deadline Exceeded {grpc_status:4, created_time:"2025-03-14T07:00:00.403807+00:00"}; on_complete = 000001653D43DFD0
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2428][GRPCLOG][DEBUG]MARK_STREAM_CLOSED: t=000001653D3390D0 s=000001653D4493F0(id=1513) read+write [UNKNOWN:Deadline Exceeded {grpc_status:4, created_time:"2025-03-14T07:00:00.403807+00:00"}]
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=0 s=000001653D4493F0 closure=0000000000000000 read_closed=1 write_closed=1 0
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=0 s=000001653D4493F0 closure=0000000000000000 read_closed=1 write_closed=1 0
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1397][GRPCLOG][INFO]complete_closure_step: t=000001653D3390D0 000001653D43DFD0 refs=0 flags=0x0000 desc=op->on_complete err=OK write_state=IDLE whence=(null):-1
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1475][GRPCLOG][INFO]perform_stream_op_locked[s=000001653D4493F0; op=000001653D37C078]:  CANCEL:UNKNOWN:Deadline Exceeded {grpc_status:4, created_time:"2025-03-14T07:00:00.403807+00:00"}; on_complete = 000001653D43DC90
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2428][GRPCLOG][DEBUG]MARK_STREAM_CLOSED: t=000001653D3390D0 s=000001653D4493F0(id=1513) read+write [UNKNOWN:Deadline Exceeded {grpc_status:4, created_time:"2025-03-14T07:00:00.403807+00:00"}]
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=0 s=000001653D4493F0 closure=0000000000000000 read_closed=1 write_closed=1 0
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=0 s=000001653D4493F0 closure=0000000000000000 read_closed=1 write_closed=1 0
[2025-03-14 15:00:00.403][25948][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1397][GRPCLOG][INFO]complete_closure_step: t=000001653D3390D0 000001653D43DC90 refs=0 flags=0x0000 desc=op->on_complete err=OK write_state=IDLE whence=(null):-1
[2025-03-14 15:00:00.434][55144][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:338][GRPCLOG][INFO]INCOMING[000001653D3390D0]: HEADERS:END_HEADERS:PRIORITY len:24 id:0x000005eb
[2025-03-14 15:00:00.434][55144][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:903][GRPCLOG][DEBUG]HTTP:000001653D3390D0/000001653D28AFF0 creating accept stream 1515 [from 00000000000005EB]
[2025-03-14 15:00:00.434][55144][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:735][GRPCLOG][INFO][t:000001653D3390D0 fd:-1 peer:ipv4:127.0.0.1:28015] Accepting new stream; num_incoming_streams_before_settings_ack=4294966538
[2025-03-14 15:00:00.434][55144][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:776][GRPCLOG][INFO]parsing initial_metadata
[2025-03-14 15:00:00.434][55144][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:911][GRPCLOG][DEBUG]INCOMING[000001653D3390D0;000001653D28AFF0]: Parse 24b last frame fragment with header
[2025-03-14 15:00:00.434][55144][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:338][GRPCLOG][INFO]INCOMING[000001653D3390D0]: DATA:END_STREAM len:75 id:0x000005eb
[2025-03-14 15:00:00.434][55144][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:911][GRPCLOG][DEBUG]INCOMING[000001653D3390D0;000001653D28AFF0]: Parse 75b last frame fragment with data
[2025-03-14 15:00:00.434][55144][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2428][GRPCLOG][DEBUG]MARK_STREAM_CLOSED: t=000001653D3390D0 s=000001653D28AFF0(id=1515) read [OK]
[2025-03-14 15:00:00.434][55144][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:3108][GRPCLOG][INFO]ipv4:127.0.0.1:28015: Keepalive ping cancelled. Resetting timer.
[2025-03-14 15:00:00.434][55144][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1747][GRPCLOG][INFO]perform_stream_op[s=000001653D28AFF0; op=000001653D28BF70]:  RECV_INITIAL_METADATA
[2025-03-14 15:00:00.434][55144][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1475][GRPCLOG][INFO]perform_stream_op_locked[s=000001653D28AFF0; op=000001653D28BF70]:  RECV_INITIAL_METADATA; on_complete = 0000000000000000
[2025-03-14 15:00:00.434][55144][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1747][GRPCLOG][INFO]perform_stream_op[s=000001653D28AFF0; op=000001653D28C250]:  RECV_MESSAGE
[2025-03-14 15:00:00.434][55144][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1475][GRPCLOG][INFO]perform_stream_op_locked[s=000001653D28AFF0; op=000001653D28C250]:  RECV_MESSAGE; on_complete = 0000000000000000
[2025-03-14 15:00:00.434][55144][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2144][GRPCLOG][DEBUG]maybe_complete_recv_message 000001653D28AFF0 final_metadata_requested=0 seen_error=0
[2025-03-14 15:00:00.434][55144][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2160][GRPCLOG][DEBUG]Deframe data frame: OK
[2025-03-14 15:00:00.434][55144][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=0 s=000001653D28AFF0 closure=0000000000000000 read_closed=1 write_closed=0 0
[2025-03-14 15:00:00.947][31780][INFO][Monitor.cpp:436]constQueueSize: 0 item, dataQueueSize: 0 item, sndQueueSize: 0 item.
[2025-03-14 15:00:00.947][31780][INFO][Monitor.cpp:478]SndMsgSize: 0.60 item/s, bandwidth: 8.40 byte/s
[2025-03-14 15:00:00.093][66080][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1007][GRPCLOG][INFO]W:000001653D29C930 SERVER [ipv4:127.0.0.1:28195] state IDLE -> WRITING [BDP_PING]
[2025-03-14 15:00:00.093][66080][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\writing.cc:140][GRPCLOG][INFO]SERVER[000001653D29C930]: Ping c22530f9c8494a1d sent [ipv4:127.0.0.1:28195]: max_pings_without_data: 0, pings_before_data_required: 0, last_ping_sent_time_: @199329ms
[2025-03-14 15:00:00.093][66080][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1007][GRPCLOG][INFO]W:000001653D29C930 SERVER [ipv4:127.0.0.1:28195] state WRITING -> WRITING [begin write in current thread]
[2025-03-14 15:00:00.093][66080][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2913][GRPCLOG][INFO]ipv4:127.0.0.1:28195: Start BDP ping err=OK
[2025-03-14 15:00:00.093][66080][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:3108][GRPCLOG][INFO]ipv4:127.0.0.1:28195: Keepalive ping cancelled. Resetting timer.
[2025-03-14 15:00:00.093][66080][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1007][GRPCLOG][INFO]W:000001653D29C930 SERVER [ipv4:127.0.0.1:28195] state WRITING -> IDLE [finish writing]
[2025-03-14 15:00:00.093][17816][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:338][GRPCLOG][INFO]INCOMING[000001653D29C930]: PING:ACK len:8 id:0x00000000
[2025-03-14 15:00:00.093][17816][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:911][GRPCLOG][DEBUG]INCOMING[000001653D29C930;0000000000000000]: Parse 8b last frame fragment with ping
[2025-03-14 15:00:00.093][17816][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:3108][GRPCLOG][INFO]ipv4:127.0.0.1:28195: Keepalive ping cancelled. Resetting timer.
[2025-03-14 15:00:00.093][17816][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2940][GRPCLOG][INFO]ipv4:127.0.0.1:28195: Complete BDP ping err=OK
[2025-03-14 15:00:00.678][49828][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1007][GRPCLOG][INFO]W:000001653D3390D0 SERVER [ipv4:127.0.0.1:28015] state IDLE -> WRITING [BDP_PING]
[2025-03-14 15:00:00.678][49828][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\writing.cc:140][GRPCLOG][INFO]SERVER[000001653D3390D0]: Ping 8bcd2510d2f3eedb sent [ipv4:127.0.0.1:28015]: max_pings_without_data: 0, pings_before_data_required: 0, last_ping_sent_time_: @199914ms
[2025-03-14 15:00:00.678][49828][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1007][GRPCLOG][INFO]W:000001653D3390D0 SERVER [ipv4:127.0.0.1:28015] state WRITING -> WRITING [begin write in current thread]
[2025-03-14 15:00:00.679][49828][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2913][GRPCLOG][INFO]ipv4:127.0.0.1:28015: Start BDP ping err=OK
[2025-03-14 15:00:00.679][49828][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:3108][GRPCLOG][INFO]ipv4:127.0.0.1:28015: Keepalive ping cancelled. Resetting timer.
[2025-03-14 15:00:00.679][49828][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1007][GRPCLOG][INFO]W:000001653D3390D0 SERVER [ipv4:127.0.0.1:28015] state WRITING -> IDLE [finish writing]
[2025-03-14 15:00:00.679][2924][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:338][GRPCLOG][INFO]INCOMING[000001653D3390D0]: PING:ACK len:8 id:0x00000000
[2025-03-14 15:00:00.679][2924][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:911][GRPCLOG][DEBUG]INCOMING[000001653D3390D0;0000000000000000]: Parse 8b last frame fragment with ping
[2025-03-14 15:00:00.679][2924][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:3108][GRPCLOG][INFO]ipv4:127.0.0.1:28015: Keepalive ping cancelled. Resetting timer.
[2025-03-14 15:00:00.679][2924][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2940][GRPCLOG][INFO]ipv4:127.0.0.1:28015: Complete BDP ping err=OK
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1747][GRPCLOG][INFO]perform_stream_op[s=000001653D384730; op=000001653D383D38]:  SEND_INITIAL_METADATA{user-agent: grpc-c++/1.60.0 grpc-c/37.0.0 (windows; chttp2), :authority: localhost:9090, :path: /XXXX/Heartbeat, grpc-timeout: @202084ms, GrpcRegisteredMethod: 0x1, WaitForReady: false, grpc-accept-encoding: identity, deflate, gzip, te: trailers, content-type: application/grpc, :scheme: http, :method: POST} SEND_MESSAGE:flags=0x00000000:len=16 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1475][GRPCLOG][INFO]perform_stream_op_locked[s=000001653D384730; op=000001653D383D38]:  SEND_INITIAL_METADATA{user-agent: grpc-c++/1.60.0 grpc-c/37.0.0 (windows; chttp2), :authority: localhost:9090, :path: /XXXX.XXXX/Heartbeat, grpc-timeout: @202084ms, GrpcRegisteredMethod: 0x1, WaitForReady: false, grpc-accept-encoding: identity, deflate, gzip, te: trailers, content-type: application/grpc, :scheme: http, :method: POST} SEND_MESSAGE:flags=0x00000000:len=16 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA; on_complete = 000001653D384538
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1453][GRPCLOG][INFO]--metadata--
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI:user-agent: grpc-c++/1.60.0 grpc-c/37.0.0 (windows; chttp2)
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI::authority: localhost:9090
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI::path: /XXXX.XXXX/Heartbeat
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI:grpc-timeout: @202084ms
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI:GrpcRegisteredMethod: 0x1
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI:WaitForReady: false
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI:grpc-accept-encoding: identity, deflate, gzip
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI:te: trailers
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI:content-type: application/grpc
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI::scheme: http
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI::method: POST
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1453][GRPCLOG][INFO]--metadata--
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1330][GRPCLOG][INFO]HTTP:CLI: Transport 000001653D6902F0 allocating new grpc_chttp2_stream 000001653D384730 to id 1503
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1007][GRPCLOG][INFO]W:000001653D6902F0 CLIENT [ipv4:127.0.0.1:9090] state IDLE -> WRITING [START_NEW_STREAM]
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1007][GRPCLOG][INFO]W:000001653D6902F0 CLIENT [ipv4:127.0.0.1:9090] state WRITING -> WRITING+MORE [SEND_MESSAGE]
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2144][GRPCLOG][DEBUG]maybe_complete_recv_message 000001653D384730 final_metadata_requested=0 seen_error=0
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=1 s=000001653D384730 closure=0000000000000000 read_closed=0 write_closed=0 0
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2144][GRPCLOG][DEBUG]maybe_complete_recv_message 000001653D384730 final_metadata_requested=1 seen_error=0
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=1 s=000001653D384730 closure=000001653D3846F8 read_closed=0 write_closed=0 0
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1397][GRPCLOG][INFO]complete_closure_step: t=000001653D6902F0 000001653D384538 refs=3 flags=0x0001 desc=op->on_complete err=OK write_state=WRITING+MORE whence=(null):-1
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\writing.cc:473][GRPCLOG][INFO]W:000001653D6902F0 CLIENT[1503] im-(sent,send)=(0,1)
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1397][GRPCLOG][INFO]complete_closure_step: t=000001653D6902F0 000001653D384538 refs=2 flags=0x0001 desc=send_initial_metadata_finished err=OK write_state=WRITING+MORE whence=(null):-1
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2428][GRPCLOG][DEBUG]MARK_STREAM_CLOSED: t=000001653D6902F0 s=000001653D384730(id=1503) write [OK]
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1397][GRPCLOG][INFO]complete_closure_step: t=000001653D6902F0 000001653D384538 refs=1 flags=0x0001 desc=send_trailing_metadata_finished err=OK write_state=WRITING+MORE whence=(null):-1
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1397][GRPCLOG][INFO]complete_closure_step: t=000001653D6902F0 000001653D384538 refs=0 flags=0x0001 desc=on_write_finished_cb err=OK write_state=WRITING+MORE whence=(null):-1
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1007][GRPCLOG][INFO]W:000001653D6902F0 CLIENT [ipv4:127.0.0.1:9090] state WRITING+MORE -> WRITING [begin write in current thread]
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1007][GRPCLOG][INFO]W:000001653D6902F0 CLIENT [ipv4:127.0.0.1:9090] state WRITING -> IDLE [finish writing]
[2025-03-14 15:00:00.848][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:338][GRPCLOG][INFO]INCOMING[000001653D6902F0]: HEADERS:END_HEADERS len:4 id:0x000005df
[2025-03-14 15:00:00.849][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:776][GRPCLOG][INFO]parsing initial_metadata
[2025-03-14 15:00:00.849][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:911][GRPCLOG][DEBUG]INCOMING[000001653D6902F0;000001653D384730]: Parse 4b last frame fragment with header
[2025-03-14 15:00:00.849][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:338][GRPCLOG][INFO]INCOMING[000001653D6902F0]: DATA len:7 id:0x000005df
[2025-03-14 15:00:00.849][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:911][GRPCLOG][DEBUG]INCOMING[000001653D6902F0;000001653D384730]: Parse 7b last frame fragment with data
[2025-03-14 15:00:00.849][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2144][GRPCLOG][DEBUG]maybe_complete_recv_message 000001653D384730 final_metadata_requested=1 seen_error=0
[2025-03-14 15:00:00.849][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2160][GRPCLOG][DEBUG]Deframe data frame: OK
[2025-03-14 15:00:00.849][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:338][GRPCLOG][INFO]INCOMING[000001653D6902F0]: HEADERS:END_STREAM:END_HEADERS len:1 id:0x000005df
[2025-03-14 15:00:00.849][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:782][GRPCLOG][INFO]parsing trailing_metadata
[2025-03-14 15:00:00.849][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:911][GRPCLOG][DEBUG]INCOMING[000001653D6902F0;000001653D384730]: Parse 1b last frame fragment with header
[2025-03-14 15:00:00.849][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=1 s=000001653D384730 closure=000001653D3846F8 read_closed=0 write_closed=1 0
[2025-03-14 15:00:00.849][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2428][GRPCLOG][DEBUG]MARK_STREAM_CLOSED: t=000001653D6902F0 s=000001653D384730(id=1503) read [OK]
[2025-03-14 15:00:00.849][12316][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=1 s=000001653D384730 closure=000001653D3846F8 read_closed=1 write_closed=1 0
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1747][GRPCLOG][INFO]perform_stream_op[s=000001653D862E30; op=000001653D862438]:  SEND_INITIAL_METADATA{user-agent: grpc-c++/1.60.0 grpc-c/37.0.0 (windows; chttp2), :authority: localhost:9920, :path: /BBBB.BBBB/Heartbeat, grpc-timeout: @202130ms, GrpcRegisteredMethod: 0x1, WaitForReady: false, grpc-accept-encoding: identity, deflate, gzip, te: trailers, content-type: application/grpc, :scheme: http, :method: POST} SEND_MESSAGE:flags=0x00000000:len=0 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1475][GRPCLOG][INFO]perform_stream_op_locked[s=000001653D862E30; op=000001653D862438]:  SEND_INITIAL_METADATA{user-agent: grpc-c++/1.60.0 grpc-c/37.0.0 (windows; chttp2), :authority: localhost:9920, :path: /BBBB.BBBB/Heartbeat, grpc-timeout: @202130ms, GrpcRegisteredMethod: 0x1, WaitForReady: false, grpc-accept-encoding: identity, deflate, gzip, te: trailers, content-type: application/grpc, :scheme: http, :method: POST} SEND_MESSAGE:flags=0x00000000:len=0 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA; on_complete = 000001653D862C38
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1453][GRPCLOG][INFO]--metadata--
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI:user-agent: grpc-c++/1.60.0 grpc-c/37.0.0 (windows; chttp2)
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI::authority: localhost:9920
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI::path: /BBBB.BBBB/Heartbeat
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI:grpc-timeout: @202130ms
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI:GrpcRegisteredMethod: 0x1
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI:WaitForReady: false
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI:grpc-accept-encoding: identity, deflate, gzip
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI:te: trailers
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI:content-type: application/grpc
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI::scheme: http
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1457][GRPCLOG][INFO]HTTP:0:HDR:CLI::method: POST
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1453][GRPCLOG][INFO]--metadata--
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1330][GRPCLOG][INFO]HTTP:CLI: Transport 000001653D701DF0 allocating new grpc_chttp2_stream 000001653D862E30 to id 267
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1007][GRPCLOG][INFO]W:000001653D701DF0 CLIENT [ipv4:127.0.0.1:9920] state IDLE -> WRITING [START_NEW_STREAM]
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1007][GRPCLOG][INFO]W:000001653D701DF0 CLIENT [ipv4:127.0.0.1:9920] state WRITING -> WRITING+MORE [SEND_MESSAGE]
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2144][GRPCLOG][DEBUG]maybe_complete_recv_message 000001653D862E30 final_metadata_requested=0 seen_error=0
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=1 s=000001653D862E30 closure=0000000000000000 read_closed=0 write_closed=0 0
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2144][GRPCLOG][DEBUG]maybe_complete_recv_message 000001653D862E30 final_metadata_requested=1 seen_error=0
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=1 s=000001653D862E30 closure=000001653D862DF8 read_closed=0 write_closed=0 0
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1397][GRPCLOG][INFO]complete_closure_step: t=000001653D701DF0 000001653D862C38 refs=3 flags=0x0001 desc=op->on_complete err=OK write_state=WRITING+MORE whence=(null):-1
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\writing.cc:473][GRPCLOG][INFO]W:000001653D701DF0 CLIENT[267] im-(sent,send)=(0,1)
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1397][GRPCLOG][INFO]complete_closure_step: t=000001653D701DF0 000001653D862C38 refs=2 flags=0x0001 desc=send_initial_metadata_finished err=OK write_state=WRITING+MORE whence=(null):-1
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2428][GRPCLOG][DEBUG]MARK_STREAM_CLOSED: t=000001653D701DF0 s=000001653D862E30(id=267) write [OK]
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1397][GRPCLOG][INFO]complete_closure_step: t=000001653D701DF0 000001653D862C38 refs=1 flags=0x0001 desc=send_trailing_metadata_finished err=OK write_state=WRITING+MORE whence=(null):-1
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1397][GRPCLOG][INFO]complete_closure_step: t=000001653D701DF0 000001653D862C38 refs=0 flags=0x0001 desc=on_write_finished_cb err=OK write_state=WRITING+MORE whence=(null):-1
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1007][GRPCLOG][INFO]W:000001653D701DF0 CLIENT [ipv4:127.0.0.1:9920] state WRITING+MORE -> WRITING [begin write in current thread]
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:1007][GRPCLOG][INFO]W:000001653D701DF0 CLIENT [ipv4:127.0.0.1:9920] state WRITING -> IDLE [finish writing]
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:338][GRPCLOG][INFO]INCOMING[000001653D701DF0]: HEADERS:END_HEADERS len:4 id:0x0000010b
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:776][GRPCLOG][INFO]parsing initial_metadata
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:911][GRPCLOG][DEBUG]INCOMING[000001653D701DF0;000001653D862E30]: Parse 4b last frame fragment with header
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:338][GRPCLOG][INFO]INCOMING[000001653D701DF0]: DATA len:7 id:0x0000010b
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:911][GRPCLOG][DEBUG]INCOMING[000001653D701DF0;000001653D862E30]: Parse 7b last frame fragment with data
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2144][GRPCLOG][DEBUG]maybe_complete_recv_message 000001653D862E30 final_metadata_requested=1 seen_error=0
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2160][GRPCLOG][DEBUG]Deframe data frame: OK
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:338][GRPCLOG][INFO]INCOMING[000001653D701DF0]: HEADERS:END_STREAM:END_HEADERS len:1 id:0x0000010b
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:782][GRPCLOG][INFO]parsing trailing_metadata
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\parsing.cc:911][GRPCLOG][DEBUG]INCOMING[000001653D701DF0;000001653D862E30]: Parse 1b last frame fragment with header
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=1 s=000001653D862E30 closure=000001653D862DF8 read_closed=0 write_closed=1 0
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2428][GRPCLOG][DEBUG]MARK_STREAM_CLOSED: t=000001653D701DF0 s=000001653D862E30(id=267) read [OK]
[2025-03-14 15:00:00.894][60140][INFO][D:\Code\grpc\1.60.0_complete\grpc\src\core\ext\transport\chttp2\transport\chttp2_transport.cc:2216][GRPCLOG][DEBUG]maybe_complete_recv_trailing_metadata cli=1 s=000001653D862E30 closure=000001653D862DF8 read_closed=1 write_closed=1 0
```
Reply all
Reply to author
Forward
0 new messages