EXC_BAD_ACCESS after queue timeout

[drcapulet]

New Issue Checklist

• Updated grpc-swift to the latest version
• I read the Contribution Guidelines
• I searched for existing GitHub issues(especially, there are many resolved issues related to SSL)

Issue Description

When running the server, if there's more than 10 minutes (source) between requests, the next request crashes with a EXC_BAD_ACCESS.

#1	0x0000000100b11b3f in ::gpr_mu_lock(gpr_mu *) at <repo>/Pods/gRPC-Core/src/core/lib/gpr/sync_posix.cc:85
#2	0x0000000100a44da9 in pollset_add_fd(grpc_pollset*, grpc_fd*) at <repo>/Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:915
#3	0x0000000100a490e8 in grpc_pollset_add_fd(grpc_pollset*, grpc_fd*) at <repo>/Pods/gRPC-Core/src/core/lib/iomgr/ev_posix.cc:336
#4	0x0000000100b16399 in tcp_add_to_pollset(grpc_endpoint*, grpc_pollset*) at <repo>/Pods/gRPC-Core/src/core/lib/iomgr/tcp_posix.cc:1030
#5	0x0000000100a3f7a0 in grpc_endpoint_add_to_pollset(grpc_endpoint*, grpc_pollset*) at <repo>/Pods/gRPC-Core/src/core/lib/iomgr/endpoint.cc:36
#6	0x0000000100a1c87d in set_pollset(grpc_transport*, grpc_stream*, grpc_pollset*) at <repo>/Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:2804
#7	0x0000000100b24364 in grpc_transport_set_pops(grpc_transport*, grpc_stream*, grpc_polling_entity*) at <repo>/Pods/gRPC-Core/src/core/lib/transport/transport.cc:185
#8	0x0000000100a39ed3 in set_pollset_or_pollset_set(grpc_call_element*, grpc_polling_entity*) at <repo>/Pods/gRPC-Core/src/core/lib/channel/connected_channel.cc:164
#9	0x0000000100a03f59 in grpc_call_stack_set_pollset_or_pollset_set(grpc_call_stack*, grpc_polling_entity*) at <repo>/Pods/gRPC-Core/src/core/lib/channel/channel_stack.cc:201
#10	0x00000001009f5e28 in grpc_call_set_completion_queue(grpc_call*, grpc_completion_queue*) at <repo>/Pods/gRPC-Core/src/core/lib/surface/call.cc:484
#11	0x0000000100ae803f in publish_call(grpc_server*, (anonymous namespace)::call_data*, unsigned long, (anonymous namespace)::requested_call*) at <repo>/Pods/gRPC-Core/src/core/lib/surface/server.cc:487
#12	0x0000000100ae7e0d in publish_new_rpc(void*, grpc_error*) at <repo>/Pods/gRPC-Core/src/core/lib/surface/server.cc:544
#13	0x0000000100ae7b91 in finish_start_new_rpc(grpc_server*, grpc_call_element*, (anonymous namespace)::request_matcher*, grpc_server_register_method_payload_handling) at <repo>/Pods/gRPC-Core/src/core/lib/surface/server.cc:600
#14	0x0000000100ae79ba in start_new_rpc(grpc_call_element*) at <repo>/Pods/gRPC-Core/src/core/lib/surface/server.cc:662
#15	0x0000000100ae7218 in got_initial_metadata(void*, grpc_error*) at <repo>/Pods/gRPC-Core/src/core/lib/surface/server.cc:839
#16	0x0000000100a4a2be in exec_ctx_run(grpc_closure*, grpc_error*) at <repo>/Pods/gRPC-Core/src/core/lib/iomgr/exec_ctx.cc:40
#17	0x0000000100a4a14a in grpc_core::ExecCtx::Flush() at <repo>/Pods/gRPC-Core/src/core/lib/iomgr/exec_ctx.cc:148
#18	0x0000000100a44afc in pollset_work(grpc_pollset*, grpc_pollset_worker**, long long) at <repo>/Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1133
#19	0x0000000100a492c0 in pollset_work(grpc_pollset*, grpc_pollset_worker**, long long) at <repo>/Pods/gRPC-Core/src/core/lib/iomgr/ev_posix.cc:321
#20	0x0000000100ac24a8 in grpc_pollset_work(grpc_pollset*, grpc_pollset_worker**, long long) at <repo>/Pods/gRPC-Core/src/core/lib/iomgr/pollset.cc:48
#21	0x0000000100a32d5e in cq_next(grpc_completion_queue*, gpr_timespec, void*) at <repo>/Pods/gRPC-Core/src/core/lib/surface/completion_queue.cc:1035
#22	0x0000000100a32083 in ::grpc_completion_queue_next(grpc_completion_queue *, gpr_timespec, void *) at <repo>/Pods/gRPC-Core/src/core/lib/surface/completion_queue.cc:1111
#23	0x00000001004fe40c in cgrpc_completion_queue_get_next_event at <repo>/Pods/SwiftGRPC/Sources/CgRPC/shim/completion_queue_shim.c:30
#24	0x00000001005202c1 in CompletionQueue.wait(timeout:) at <repo>/Pods/SwiftGRPC/Sources/SwiftGRPC/Core/CompletionQueue.swift:97
#25	0x00000001005319de in closure #1 in Server.run(handlerFunction:) at <repo>/Pods/SwiftGRPC/Sources/SwiftGRPC/Core/Server.swift:79

Complete output when running grpc-swift, including the stack trace and command used

D0723 12:36:09.191887000 4296046016 ev_posix.cc:170]                   Using polling engine: poll
D0723 12:36:09.191987000 4296046016 dns_resolver.cc:334]               Using native dns resolver
I0723 12:36:09.192040000 4296046016 timer_manager.cc:94]               Spawn timer thread
I0723 12:36:09.192053000 4296046016 init.cc:155]                       grpc_init(void)
I0723 12:36:09.192092000 123145438097408 timer_generic.cc:715]         TIMER CHECK BEGIN: now=0 next=9223372036854775807 tls_min=0 glob_min=0
I0723 12:36:09.192101000 123145438097408 timer_generic.cc:610]           .. shard[0]->min_deadline = 1
I0723 12:36:09.192108000 123145438097408 timer_generic.cc:738]         TIMER CHECK END: r=1; next=1
I0723 12:36:09.192111000 123145438097408 timer_manager.cc:194]         sleep for a 1 milliseconds
I0723 12:36:09.192126000 4296046016 server.cc:1015]                    grpc_server_create(0x0, 0x0)
I0723 12:36:09.192158000 4296046016 completion_queue.cc:481]           grpc_completion_queue_create_internal(completion_type=0, polling_type=0)
I0723 12:36:09.192166000 4296046016 ev_posix.cc:302]                   (polling-api) pollset_init(0x101705fd8)
I0723 12:36:09.192258000 4296046016 server.cc:998]                     grpc_server_register_completion_queue(server=0x1017045a0, cq=0x101705ed0, reserved=0x0)
D0723 12:36:09.192266000 4296046016 server.cc:986]                     CQ:0x101705ed0   ref 2 -> 3 server
I0723 12:36:09.192274000 4296046016 server_chttp2.cc:34]               grpc_server_add_insecure_http2_port(server=0x1017045a0, addr=localhost:8081)
I0723 12:36:09.192878000 123145438097408 timer_manager.cc:214]         wait ended: was_timed:1 kicked:0
I0723 12:36:09.192887000 123145438097408 timer_generic.cc:715]         TIMER CHECK BEGIN: now=1 next=9223372036854775807 tls_min=0 glob_min=1
I0723 12:36:09.192891000 123145438097408 timer_generic.cc:610]           .. shard[0]->min_deadline = 1
I0723 12:36:09.192906000 123145438097408 timer_generic.cc:533]           .. shard[0]: heap_empty=true
I0723 12:36:09.192909000 123145438097408 timer_generic.cc:508]           .. shard[0]->queue_deadline_cap --> 1001
I0723 12:36:09.193362000 4296046016 socket_utils_common_posix.cc:315]  TCP_USER_TIMEOUT not supported for this platform
I0723 12:36:09.195025000 123145438097408 timer_generic.cc:573]           .. shard[0] popped 0
I0723 12:36:09.195036000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[0]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.195043000 123145438097408 timer_generic.cc:533]           .. shard[1]: heap_empty=true
I0723 12:36:09.195048000 123145438097408 timer_generic.cc:508]           .. shard[1]->queue_deadline_cap --> 1001
I0723 12:36:09.195052000 123145438097408 timer_generic.cc:573]           .. shard[1] popped 0
I0723 12:36:09.195071000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[1]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.195075000 123145438097408 timer_generic.cc:533]           .. shard[2]: heap_empty=true
I0723 12:36:09.195099000 123145438097408 timer_generic.cc:508]           .. shard[2]->queue_deadline_cap --> 1001
I0723 12:36:09.195103000 123145438097408 timer_generic.cc:573]           .. shard[2] popped 0
I0723 12:36:09.195115000 4296046016 ev_posix.cc:252]                   (polling-api) fd_create(5, tcp-server-listener:[::1]:8081, 1)
I0723 12:36:09.195304000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[2]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.195310000 4296046016 ev_posix.cc:253]                   (fd-trace) fd_create(5, tcp-server-listener:[::1]:8081, 1)
I0723 12:36:09.195314000 123145438097408 timer_generic.cc:533]           .. shard[3]: heap_empty=true
I0723 12:36:09.195319000 123145438097408 timer_generic.cc:508]           .. shard[3]->queue_deadline_cap --> 1001
I0723 12:36:09.195323000 123145438097408 timer_generic.cc:573]           .. shard[3] popped 0
I0723 12:36:09.195327000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[3]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.195332000 123145438097408 timer_generic.cc:533]           .. shard[4]: heap_empty=true
I0723 12:36:09.195335000 123145438097408 timer_generic.cc:508]           .. shard[4]->queue_deadline_cap --> 1001
I0723 12:36:09.195531000 123145438097408 timer_generic.cc:573]           .. shard[4] popped 0
I0723 12:36:09.195344000 4296046016 socket_utils_common_posix.cc:315]  TCP_USER_TIMEOUT not supported for this platform
I0723 12:36:09.195541000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[4]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.195566000 4296046016 ev_posix.cc:252]                   (polling-api) fd_create(6, tcp-server-listener:127.0.0.1:8081, 1)
I0723 12:36:09.195572000 4296046016 ev_posix.cc:253]                   (fd-trace) fd_create(6, tcp-server-listener:127.0.0.1:8081, 1)
I0723 12:36:09.195559000 123145438097408 timer_generic.cc:533]           .. shard[5]: heap_empty=true
I0723 12:36:09.195579000 123145438097408 timer_generic.cc:508]           .. shard[5]->queue_deadline_cap --> 1001
I0723 12:36:09.195583000 123145438097408 timer_generic.cc:573]           .. shard[5] popped 0
I0723 12:36:09.195637000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[5]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.195644000 123145438097408 timer_generic.cc:533]           .. shard[6]: heap_empty=true
I0723 12:36:09.195649000 123145438097408 timer_generic.cc:508]           .. shard[6]->queue_deadline_cap --> 1001
I0723 12:36:09.195653000 123145438097408 timer_generic.cc:573]           .. shard[6] popped 0
I0723 12:36:09.195655000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[6]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.195658000 123145438097408 timer_generic.cc:533]           .. shard[7]: heap_empty=true
I0723 12:36:09.195661000 123145438097408 timer_generic.cc:508]           .. shard[7]->queue_deadline_cap --> 1001
I0723 12:36:09.195663000 123145438097408 timer_generic.cc:573]           .. shard[7] popped 0
I0723 12:36:09.195671000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[7]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.195683000 123145438097408 timer_generic.cc:533]           .. shard[8]: heap_empty=true
I0723 12:36:09.195813000 4296046016 server.cc:1119]                    grpc_server_start(server=0x1017045a0)
I0723 12:36:09.195821000 123145438097408 timer_generic.cc:508]           .. shard[8]->queue_deadline_cap --> 1001
I0723 12:36:09.195825000 4296046016 executor.cc:298]                   EXECUTOR (default-executor) try to schedule 0x600002610730 (short) (created /Pods/gRPC-Core/src/core/lib/surface/server.cc:1141) to thread 0
I0723 12:36:09.195834000 123145438097408 timer_generic.cc:573]           .. shard[8] popped 0
I0723 12:36:09.195870000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[8]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.195879000 123145438097408 timer_generic.cc:533]           .. shard[9]: heap_empty=true
I0723 12:36:09.195855000 123145437024256 executor.cc:246]              EXECUTOR (default-executor) [0]: execute
I0723 12:36:09.195885000 123145438097408 timer_generic.cc:508]           .. shard[9]->queue_deadline_cap --> 1001
I0723 12:36:09.195903000 123145437024256 executor.cc:128]              EXECUTOR (default-executor) run 0x600002610730 [created by /Pods/gRPC-Core/src/core/lib/surface/server.cc:1141]
I0723 12:36:09.195951000 123145438097408 timer_generic.cc:573]           .. shard[9] popped 0
I0723 12:36:09.195962000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[9]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.195962000 123145437024256 ev_posix.cc:335]              (polling-api) pollset_add_fd(0x101705fd8, 5)
I0723 12:36:09.195970000 123145438097408 timer_generic.cc:533]           .. shard[10]: heap_empty=true
I0723 12:36:09.195975000 123145438097408 timer_generic.cc:508]           .. shard[10]->queue_deadline_cap --> 1001
I0723 12:36:09.195980000 123145438097408 timer_generic.cc:573]           .. shard[10] popped 0
D0723 12:36:09.195980000 123145437024256 ev_poll_posix.cc:371]         FD 5 0x600003b18000   ref 2 1 -> 3 [multipoller; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:928]
I0723 12:36:09.195987000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[10]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.196184000 123145437024256 ev_posix.cc:335]              (polling-api) pollset_add_fd(0x101705fd8, 6)
I0723 12:36:09.196198000 123145438097408 timer_generic.cc:533]           .. shard[11]: heap_empty=true
D0723 12:36:09.196208000 123145437024256 ev_poll_posix.cc:371]         FD 6 0x600003b100e0   ref 2 1 -> 3 [multipoller; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:928]
I0723 12:36:09.196217000 123145438097408 timer_generic.cc:508]           .. shard[11]->queue_deadline_cap --> 1001
I0723 12:36:09.196229000 123145438097408 timer_generic.cc:573]           .. shard[11] popped 0
I0723 12:36:09.196223000 123145437024256 executor.cc:225]              EXECUTOR (default-executor) [0]: step (sub_depth=1)
I0723 12:36:09.196235000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[11]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.196280000 123145435414528 metadata_array.cc:29]         grpc_metadata_array_init(array=0x60000300c880)
I0723 12:36:09.196371000 123145438097408 timer_generic.cc:533]           .. shard[12]: heap_empty=true
I0723 12:36:09.196447000 123145438097408 timer_generic.cc:508]           .. shard[12]->queue_deadline_cap --> 1001
I0723 12:36:09.196454000 123145438097408 timer_generic.cc:573]           .. shard[12] popped 0
I0723 12:36:09.196457000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[12]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.196479000 123145438097408 timer_generic.cc:533]           .. shard[13]: heap_empty=true
I0723 12:36:09.196506000 123145438097408 timer_generic.cc:508]           .. shard[13]->queue_deadline_cap --> 1001
I0723 12:36:09.196454000 123145435414528 call_details.cc:31]           grpc_call_details_init(cd=0x60000300c898)
I0723 12:36:09.196511000 123145438097408 timer_generic.cc:573]           .. shard[13] popped 0
I0723 12:36:09.196718000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[13]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.196740000 123145438097408 timer_generic.cc:533]           .. shard[14]: heap_empty=true
I0723 12:36:09.196707000 123145435414528 completion_queue.cc:481]      grpc_completion_queue_create_internal(completion_type=0, polling_type=0)
I0723 12:36:09.196744000 123145438097408 timer_generic.cc:508]           .. shard[14]->queue_deadline_cap --> 1001
I0723 12:36:09.196783000 123145435414528 ev_posix.cc:302]              (polling-api) pollset_init(0x101501258)
I0723 12:36:09.196787000 123145438097408 timer_generic.cc:573]           .. shard[14] popped 0
I0723 12:36:09.196792000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[14]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.196795000 123145438097408 timer_generic.cc:533]           .. shard[15]: heap_empty=true
I0723 12:36:09.196797000 123145435414528 metadata_array.cc:29]         grpc_metadata_array_init(array=0x6000002246a0)
I0723 12:36:09.196959000 123145438097408 timer_generic.cc:508]           .. shard[15]->queue_deadline_cap --> 1001
I0723 12:36:09.197020000 123145438097408 timer_generic.cc:573]           .. shard[15] popped 0
I0723 12:36:09.197026000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[15]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.197030000 123145438097408 timer_generic.cc:533]           .. shard[16]: heap_empty=true
I0723 12:36:09.197030000 123145435414528 server.cc:1487]               grpc_server_request_call(server=0x1017045a0, call=0x60000300c8f8, details=0x60000300c898, initial_metadata=0x6000002246a0, cq_bound_to_call=0x101501150, cq_for_notification=0x101705ed0, tag=0x65)
I0723 12:36:09.197032000 123145438097408 timer_generic.cc:508]           .. shard[16]->queue_deadline_cap --> 1001
I0723 12:36:09.197153000 123145435414528 completion_queue.cc:959]      grpc_completion_queue_next(cq=0x101705ed0, deadline=gpr_timespec { tv_sec: 600, tv_nsec: 5497813, clock_type: 0 }, reserved=0x0)
I0723 12:36:09.197172000 123145438097408 timer_generic.cc:573]           .. shard[16] popped 0
I0723 12:36:09.197186000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[16]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.197189000 123145438097408 timer_generic.cc:533]           .. shard[17]: heap_empty=true
I0723 12:36:09.197192000 123145438097408 timer_generic.cc:508]           .. shard[17]->queue_deadline_cap --> 1001
I0723 12:36:09.197209000 123145438097408 timer_generic.cc:573]           .. shard[17] popped 0
I0723 12:36:09.197212000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[17]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.197214000 123145438097408 timer_generic.cc:533]           .. shard[18]: heap_empty=true
I0723 12:36:09.197237000 123145438097408 timer_generic.cc:508]           .. shard[18]->queue_deadline_cap --> 1001
D0723 12:36:09.197237000 123145435414528 completion_queue.cc:937]      PENDING TAGS: 0x65
I0723 12:36:09.197443000 123145438097408 timer_generic.cc:573]           .. shard[18] popped 0
I0723 12:36:09.197454000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[18]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.197460000 123145438097408 timer_generic.cc:533]           .. shard[19]: heap_empty=true
I0723 12:36:09.197479000 123145438097408 timer_generic.cc:508]           .. shard[19]->queue_deadline_cap --> 1001
D0723 12:36:09.197452000 123145435414528 completion_queue.cc:964]      CQ:0x101705ed0   ref 3 -> 4 next
I0723 12:36:09.197482000 123145438097408 timer_generic.cc:573]           .. shard[19] popped 0
I0723 12:36:09.197514000 123145435414528 ev_posix.cc:320]              (polling-api) pollset_work(0x101705fd8, 600006) begin
I0723 12:36:09.197541000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[19]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.197578000 123145435414528 ev_posix.cc:323]              (polling-api) pollset_work(0x101705fd8, 600006) end
I0723 12:36:09.197805000 123145435414528 ev_posix.cc:320]              (polling-api) pollset_work(0x101705fd8, 600006) begin
D0723 12:36:09.197832000 123145435414528 ev_poll_posix.cc:371]         FD 5 0x600003b18000   ref 2 3 -> 5 [multipoller_start; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1043]
I0723 12:36:09.197778000 123145438097408 timer_generic.cc:533]           .. shard[20]: heap_empty=true
D0723 12:36:09.197838000 123145435414528 ev_poll_posix.cc:371]         FD 6 0x600003b100e0   ref 2 3 -> 5 [multipoller_start; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1043]
D0723 12:36:09.197860000 123145435414528 ev_poll_posix.cc:371]         FD 5 0x600003b18000   ref 2 5 -> 7 [poll; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:647]
I0723 12:36:09.197848000 123145438097408 timer_generic.cc:508]           .. shard[20]->queue_deadline_cap --> 1001
D0723 12:36:09.197880000 123145435414528 ev_poll_posix.cc:388]         FD 5 0x600003b18000 unref 2 7 -> 5 [multipoller_start; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1056]
I0723 12:36:09.197958000 123145438097408 timer_generic.cc:573]           .. shard[20] popped 0
D0723 12:36:09.197988000 123145435414528 ev_poll_posix.cc:371]         FD 6 0x600003b100e0   ref 2 5 -> 7 [poll; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:647]
I0723 12:36:09.197992000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[20]->min_deadline 1 --> 1002, now=1
D0723 12:36:09.197994000 123145435414528 ev_poll_posix.cc:388]         FD 6 0x600003b100e0 unref 2 7 -> 5 [multipoller_start; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1056]
I0723 12:36:09.197999000 123145438097408 timer_generic.cc:533]           .. shard[21]: heap_empty=true
I0723 12:36:09.198157000 123145438097408 timer_generic.cc:508]           .. shard[21]->queue_deadline_cap --> 1001
I0723 12:36:09.198163000 123145438097408 timer_generic.cc:573]           .. shard[21] popped 0
I0723 12:36:09.198166000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[21]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.198169000 123145438097408 timer_generic.cc:533]           .. shard[22]: heap_empty=true
I0723 12:36:09.198171000 123145438097408 timer_generic.cc:508]           .. shard[22]->queue_deadline_cap --> 1001
I0723 12:36:09.198174000 123145438097408 timer_generic.cc:573]           .. shard[22] popped 0
I0723 12:36:09.198176000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[22]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.198179000 123145438097408 timer_generic.cc:533]           .. shard[23]: heap_empty=true
I0723 12:36:09.198351000 123145438097408 timer_generic.cc:508]           .. shard[23]->queue_deadline_cap --> 1001
I0723 12:36:09.198372000 123145438097408 timer_generic.cc:573]           .. shard[23] popped 0
I0723 12:36:09.198376000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[23]->min_deadline 1 --> 1002, now=1
I0723 12:36:09.198401000 123145438097408 timer_generic.cc:738]         TIMER CHECK END: r=1; next=1002
I0723 12:36:09.198405000 123145438097408 timer_manager.cc:194]         sleep for a 1001 milliseconds
I0723 12:36:10.198793000 123145438097408 timer_manager.cc:214]         wait ended: was_timed:1 kicked:0
....
I0723 12:46:33.397218000 123145438097408 timer_generic.cc:715]         TIMER CHECK BEGIN: now=624208 next=9223372036854775807 tls_min=624197 glob_min=624208

I0723 12:46:33.397224000 123145438097408 timer_generic.cc:610]           .. shard[22]->min_deadline = 624208

I0723 12:46:33.397228000 123145438097408 timer_generic.cc:533]           .. shard[22]: heap_empty=true

I0723 12:46:33.397232000 123145438097408 timer_generic.cc:508]           .. shard[22]->queue_deadline_cap --> 625208

I0723 12:46:33.397236000 123145438097408 timer_generic.cc:573]           .. shard[22] popped 0

I0723 12:46:33.397240000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[22]->min_deadline 624208 --> 625209, now=624208

I0723 12:46:33.397245000 123145438097408 timer_generic.cc:533]           .. shard[14]: heap_empty=true

I0723 12:46:33.397248000 123145438097408 timer_generic.cc:508]           .. shard[14]->queue_deadline_cap --> 625208

I0723 12:46:33.397254000 123145438097408 timer_generic.cc:573]           .. shard[14] popped 0

I0723 12:46:33.397260000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[14]->min_deadline 624208 --> 625209, now=624208

I0723 12:46:33.397264000 123145438097408 timer_generic.cc:533]           .. shard[16]: heap_empty=true

I0723 12:46:33.397270000 123145438097408 timer_generic.cc:508]           .. shard[16]->queue_deadline_cap --> 625208

I0723 12:46:33.397274000 123145438097408 timer_generic.cc:573]           .. shard[16] popped 0

I0723 12:46:33.397278000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[16]->min_deadline 624208 --> 625209, now=624208

I0723 12:46:33.399617000 123145438097408 timer_generic.cc:533]           .. shard[13]: heap_empty=true

I0723 12:46:33.399627000 123145438097408 timer_generic.cc:508]           .. shard[13]->queue_deadline_cap --> 625208

I0723 12:46:33.399632000 123145438097408 timer_generic.cc:573]           .. shard[13] popped 0

I0723 12:46:33.399637000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[13]->min_deadline 624208 --> 625209, now=624208

I0723 12:46:33.399641000 123145438097408 timer_generic.cc:738]         TIMER CHECK END: r=1; next=625199

I0723 12:46:33.399646000 123145438097408 timer_manager.cc:194]         sleep for a 991 milliseconds

I0723 12:46:34.389634000 123145438097408 timer_manager.cc:214]         wait ended: was_timed:1 kicked:0

I0723 12:46:34.389708000 123145438097408 timer_generic.cc:715]         TIMER CHECK BEGIN: now=625200 next=9223372036854775807 tls_min=624208 glob_min=625199

I0723 12:46:34.389724000 123145438097408 timer_generic.cc:610]           .. shard[0]->min_deadline = 625199

I0723 12:46:34.389735000 123145438097408 timer_generic.cc:533]           .. shard[0]: heap_empty=true

I0723 12:46:34.389747000 123145438097408 timer_generic.cc:508]           .. shard[0]->queue_deadline_cap --> 626199

I0723 12:46:34.389757000 123145438097408 timer_generic.cc:573]           .. shard[0] popped 0

I0723 12:46:34.389769000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[0]->min_deadline 625199 --> 626200, now=625200

I0723 12:46:34.389779000 123145438097408 timer_generic.cc:533]           .. shard[1]: heap_empty=true

I0723 12:46:34.389787000 123145438097408 timer_generic.cc:508]           .. shard[1]->queue_deadline_cap --> 626199

I0723 12:46:34.389796000 123145438097408 timer_generic.cc:573]           .. shard[1] popped 0

I0723 12:46:34.389806000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[1]->min_deadline 625199 --> 626200, now=625200

I0723 12:46:34.389814000 123145438097408 timer_generic.cc:533]           .. shard[2]: heap_empty=true

I0723 12:46:34.389822000 123145438097408 timer_generic.cc:508]           .. shard[2]->queue_deadline_cap --> 626199

I0723 12:46:34.389830000 123145438097408 timer_generic.cc:573]           .. shard[2] popped 0

I0723 12:46:34.389840000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[2]->min_deadline 625199 --> 626200, now=625200

I0723 12:46:34.390477000 123145438097408 timer_generic.cc:533]           .. shard[3]: heap_empty=true

I0723 12:46:34.390503000 123145438097408 timer_generic.cc:508]           .. shard[3]->queue_deadline_cap --> 626199

I0723 12:46:34.390514000 123145438097408 timer_generic.cc:573]           .. shard[3] popped 0

I0723 12:46:34.390527000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[3]->min_deadline 625199 --> 626200, now=625200

I0723 12:46:34.390537000 123145438097408 timer_generic.cc:533]           .. shard[4]: heap_empty=true

I0723 12:46:34.390544000 123145438097408 timer_generic.cc:508]           .. shard[4]->queue_deadline_cap --> 626199

I0723 12:46:34.390552000 123145438097408 timer_generic.cc:573]           .. shard[4] popped 0

I0723 12:46:34.390561000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[4]->min_deadline 625199 --> 626200, now=625200

I0723 12:46:34.398262000 123145438097408 timer_generic.cc:533]           .. shard[5]: heap_empty=true

I0723 12:46:34.398283000 123145438097408 timer_generic.cc:508]           .. shard[5]->queue_deadline_cap --> 626199

I0723 12:46:34.398289000 123145438097408 timer_generic.cc:573]           .. shard[5] popped 0

I0723 12:46:34.398293000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[5]->min_deadline 625199 --> 626200, now=625200

I0723 12:46:34.398298000 123145438097408 timer_generic.cc:533]           .. shard[6]: heap_empty=true

I0723 12:46:34.398301000 123145438097408 timer_generic.cc:508]           .. shard[6]->queue_deadline_cap --> 626199

I0723 12:46:34.398305000 123145438097408 timer_generic.cc:573]           .. shard[6] popped 0

I0723 12:46:34.398308000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[6]->min_deadline 625199 --> 626200, now=625200

I0723 12:46:34.398312000 123145438097408 timer_generic.cc:533]           .. shard[7]: heap_empty=true

I0723 12:46:34.398315000 123145438097408 timer_generic.cc:508]           .. shard[7]->queue_deadline_cap --> 626199

I0723 12:46:34.398443000 123145438097408 timer_generic.cc:573]           .. shard[7] popped 0

I0723 12:46:34.398458000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[7]->min_deadline 625199 --> 626200, now=625200

I0723 12:46:34.398476000 123145438097408 timer_generic.cc:533]           .. shard[8]: heap_empty=true

I0723 12:46:34.398485000 123145438097408 timer_generic.cc:508]           .. shard[8]->queue_deadline_cap --> 626199

I0723 12:46:34.398491000 123145438097408 timer_generic.cc:573]           .. shard[8] popped 0

I0723 12:46:34.398497000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[8]->min_deadline 625199 --> 626200, now=625200

I0723 12:46:34.398502000 123145438097408 timer_generic.cc:533]           .. shard[9]: heap_empty=true

I0723 12:46:34.398505000 123145438097408 timer_generic.cc:508]           .. shard[9]->queue_deadline_cap --> 626199

I0723 12:46:34.398509000 123145438097408 timer_generic.cc:573]           .. shard[9] popped 0

I0723 12:46:34.398633000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[9]->min_deadline 625199 --> 626200, now=625200

I0723 12:46:34.398647000 123145438097408 timer_generic.cc:533]           .. shard[10]: heap_empty=true

I0723 12:46:34.398654000 123145438097408 timer_generic.cc:508]           .. shard[10]->queue_deadline_cap --> 626199

I0723 12:46:34.398659000 123145438097408 timer_generic.cc:573]           .. shard[10] popped 0

I0723 12:46:34.398663000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[10]->min_deadline 625199 --> 626200, now=625200

I0723 12:46:34.398667000 123145438097408 timer_generic.cc:533]           .. shard[11]: heap_empty=true

I0723 12:46:34.398670000 123145438097408 timer_generic.cc:508]           .. shard[11]->queue_deadline_cap --> 626199

I0723 12:46:34.398674000 123145438097408 timer_generic.cc:573]           .. shard[11] popped 0

I0723 12:46:34.398678000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[11]->min_deadline 625199 --> 626200, now=625200

I0723 12:46:34.398841000 123145438097408 timer_generic.cc:533]           .. shard[12]: heap_empty=true

I0723 12:46:34.398852000 123145438097408 timer_generic.cc:508]           .. shard[12]->queue_deadline_cap --> 626199

I0723 12:46:34.398856000 123145438097408 timer_generic.cc:573]           .. shard[12] popped 0

I0723 12:46:34.398860000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[12]->min_deadline 625199 --> 626200, now=625200

I0723 12:46:34.398864000 123145438097408 timer_generic.cc:533]           .. shard[15]: heap_empty=true

I0723 12:46:34.398868000 123145438097408 timer_generic.cc:508]           .. shard[15]->queue_deadline_cap --> 626199

I0723 12:46:34.398871000 123145438097408 timer_generic.cc:573]           .. shard[15] popped 0

I0723 12:46:34.398875000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[15]->min_deadline 625199 --> 626200, now=625200

I0723 12:46:34.399041000 123145438097408 timer_generic.cc:533]           .. shard[17]: heap_empty=true

I0723 12:46:34.399067000 123145438097408 timer_generic.cc:508]           .. shard[17]->queue_deadline_cap --> 626199

I0723 12:46:34.399079000 123145438097408 timer_generic.cc:573]           .. shard[17] popped 0

I0723 12:46:34.399085000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[17]->min_deadline 625199 --> 626200, now=625200

I0723 12:46:34.399089000 123145438097408 timer_generic.cc:533]           .. shard[18]: heap_empty=true

I0723 12:46:34.399092000 123145438097408 timer_generic.cc:508]           .. shard[18]->queue_deadline_cap --> 626199

I0723 12:46:34.399096000 123145438097408 timer_generic.cc:573]           .. shard[18] popped 0

I0723 12:46:34.399100000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[18]->min_deadline 625199 --> 626200, now=625200

I0723 12:46:34.399103000 123145438097408 timer_generic.cc:533]           .. shard[19]: heap_empty=true

I0723 12:46:34.399221000 123145438097408 timer_generic.cc:508]           .. shard[19]->queue_deadline_cap --> 626199

I0723 12:46:34.399229000 123145438097408 timer_generic.cc:573]           .. shard[19] popped 0

I0723 12:46:34.399234000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[19]->min_deadline 625199 --> 626200, now=625200

I0723 12:46:34.399239000 123145438097408 timer_generic.cc:533]           .. shard[20]: heap_empty=true

I0723 12:46:34.399242000 123145438097408 timer_generic.cc:508]           .. shard[20]->queue_deadline_cap --> 626199

I0723 12:46:34.399246000 123145438097408 timer_generic.cc:573]           .. shard[20] popped 0

I0723 12:46:34.399249000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[20]->min_deadline 625199 --> 626200, now=625200

I0723 12:46:34.399253000 123145438097408 timer_generic.cc:533]           .. shard[21]: heap_empty=true

I0723 12:46:34.399256000 123145438097408 timer_generic.cc:508]           .. shard[21]->queue_deadline_cap --> 626199

I0723 12:46:34.399412000 123145438097408 timer_generic.cc:573]           .. shard[21] popped 0

I0723 12:46:34.399422000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[21]->min_deadline 625199 --> 626200, now=625200

I0723 12:46:34.399427000 123145438097408 timer_generic.cc:533]           .. shard[23]: heap_empty=true

I0723 12:46:34.399431000 123145438097408 timer_generic.cc:508]           .. shard[23]->queue_deadline_cap --> 626199

I0723 12:46:34.399434000 123145438097408 timer_generic.cc:573]           .. shard[23] popped 0

I0723 12:46:34.399438000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[23]->min_deadline 625199 --> 626200, now=625200

I0723 12:46:34.399443000 123145438097408 timer_generic.cc:738]         TIMER CHECK END: r=1; next=625209

I0723 12:46:34.399447000 123145438097408 timer_manager.cc:194]         sleep for a 9 milliseconds

I0723 12:46:34.399453000 123145438097408 timer_manager.cc:214]         wait ended: was_timed:1 kicked:0

I0723 12:46:34.399562000 123145438097408 timer_generic.cc:715]         TIMER CHECK BEGIN: now=625210 next=9223372036854775807 tls_min=625199 glob_min=625209

I0723 12:46:34.399572000 123145438097408 timer_generic.cc:610]           .. shard[13]->min_deadline = 625209

I0723 12:46:34.399577000 123145438097408 timer_generic.cc:533]           .. shard[13]: heap_empty=true

I0723 12:46:34.399581000 123145438097408 timer_generic.cc:508]           .. shard[13]->queue_deadline_cap --> 626210

I0723 12:46:34.399584000 123145438097408 timer_generic.cc:573]           .. shard[13] popped 0

I0723 12:46:34.399589000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[13]->min_deadline 625209 --> 626211, now=625210

I0723 12:46:34.399593000 123145438097408 timer_generic.cc:533]           .. shard[16]: heap_empty=true

I0723 12:46:34.399596000 123145438097408 timer_generic.cc:508]           .. shard[16]->queue_deadline_cap --> 626210

I0723 12:46:34.399600000 123145438097408 timer_generic.cc:573]           .. shard[16] popped 0

I0723 12:46:34.399723000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[16]->min_deadline 625209 --> 626211, now=625210

I0723 12:46:34.399735000 123145438097408 timer_generic.cc:533]           .. shard[14]: heap_empty=true

I0723 12:46:34.399740000 123145438097408 timer_generic.cc:508]           .. shard[14]->queue_deadline_cap --> 626210

I0723 12:46:34.399744000 123145438097408 timer_generic.cc:573]           .. shard[14] popped 0

I0723 12:46:34.399748000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[14]->min_deadline 625209 --> 626211, now=625210

I0723 12:46:34.399752000 123145438097408 timer_generic.cc:533]           .. shard[22]: heap_empty=true

I0723 12:46:34.399756000 123145438097408 timer_generic.cc:508]           .. shard[22]->queue_deadline_cap --> 626210

I0723 12:46:34.399759000 123145438097408 timer_generic.cc:573]           .. shard[22] popped 0

I0723 12:46:34.399763000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[22]->min_deadline 625209 --> 626211, now=625210

I0723 12:46:34.399918000 123145438097408 timer_generic.cc:738]         TIMER CHECK END: r=1; next=626200

I0723 12:46:34.399925000 123145438097408 timer_manager.cc:194]         sleep for a 990 milliseconds

I0723 12:46:35.152044000 123145435414528 ev_poll_posix.cc:1067]        0x101705fd8 poll=0

D0723 12:46:35.152109000 123145435414528 ev_poll_posix.cc:388]         FD 5 0x600003b18000 unref 2 5 -> 3 [poll; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:740]

D0723 12:46:35.152125000 123145435414528 ev_poll_posix.cc:388]         FD 6 0x600003b100e0 unref 2 5 -> 3 [poll; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:740]

I0723 12:46:35.152139000 123145435414528 ev_posix.cc:323]              (polling-api) pollset_work(0x101705fd8, 625955) end

D0723 12:46:35.152156000 123145435414528 completion_queue.cc:937]      PENDING TAGS: 0x65

I0723 12:46:35.152169000 123145435414528 completion_queue.cc:1059]     RETURN_EVENT[0x101705ed0]: QUEUE_TIMEOUT

D0723 12:46:35.152180000 123145435414528 completion_queue.cc:1060]     CQ:0x101705ed0 unref 4 -> 3 next

I0723 12:47:21.242654000 123145438097408 timer_manager.cc:214]         wait ended: was_timed:1 kicked:0

I0723 12:47:23.248351000 123145438097408 timer_generic.cc:715]         TIMER CHECK BEGIN: now=674057 next=9223372036854775807 tls_min=625209 glob_min=626200

I0723 12:47:23.248373000 123145438097408 timer_generic.cc:610]           .. shard[23]->min_deadline = 626200

I0723 12:47:23.248378000 123145438097408 timer_generic.cc:533]           .. shard[23]: heap_empty=true

I0723 12:47:23.248383000 123145438097408 timer_generic.cc:508]           .. shard[23]->queue_deadline_cap --> 675056

I0723 12:47:23.248386000 123145438097408 timer_generic.cc:573]           .. shard[23] popped 0

I0723 12:47:23.248391000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[23]->min_deadline 626200 --> 675057, now=674057

I0723 12:47:23.248348000 123145435414528 completion_queue.cc:1386]     grpc_completion_queue_shutdown(cq=0x104700290)

I0723 12:47:23.248396000 123145438097408 timer_generic.cc:533]           .. shard[21]: heap_empty=true

D0723 12:47:23.248408000 123145435414528 completion_queue.cc:1091]     CQ:0x104700290   ref 2 -> 3 shutting_down

I0723 12:47:23.248423000 123145438097408 timer_generic.cc:508]           .. shard[21]->queue_deadline_cap --> 675056

I0723 12:47:23.248453000 123145438097408 timer_generic.cc:573]           .. shard[21] popped 0

I0723 12:47:23.248460000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[21]->min_deadline 626200 --> 675057, now=674057

I0723 12:47:23.248442000 123145435414528 ev_posix.cc:307]              (polling-api) pollset_shutdown(0x104700398)

I0723 12:47:23.259372000 123145438097408 timer_generic.cc:533]           .. shard[20]: heap_empty=true

D0723 12:47:23.259372000 123145435414528 completion_queue.cc:1106]     CQ:0x104700290 unref 3 -> 2 shutting_down

I0723 12:47:23.259393000 123145438097408 timer_generic.cc:508]           .. shard[20]->queue_deadline_cap --> 675056

D0723 12:47:23.259409000 123145435414528 exec_ctx.cc:34]               running closure 0x1047002c8: created [/Pods/gRPC-Core/src/core/lib/surface/completion_queue.cc:504]: scheduled [/Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:940]

I0723 12:47:23.259423000 123145438097408 timer_generic.cc:573]           .. shard[20] popped 0

D0723 12:47:23.259435000 123145435414528 completion_queue.cc:583]      CQ:0x104700290 unref 2 -> 1 pollset_destroy

D0723 12:47:23.259451000 123145435414528 exec_ctx.cc:43]               closure 0x1047002c8 finished

I0723 12:47:23.259444000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[20]->min_deadline 626200 --> 675057, now=674057

I0723 12:47:23.259541000 123145435414528 metadata_array.cc:34]         grpc_metadata_array_destroy(array=0x600003020010)

I0723 12:47:23.259548000 123145438097408 timer_generic.cc:533]           .. shard[19]: heap_empty=true

I0723 12:47:23.259570000 123145438097408 timer_generic.cc:508]           .. shard[19]->queue_deadline_cap --> 675056

I0723 12:47:23.259578000 123145438097408 timer_generic.cc:573]           .. shard[19] popped 0

I0723 12:47:23.259558000 123145435414528 call_details.cc:38]           grpc_call_details_destroy(cd=0x600003020028)

I0723 12:47:23.259582000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[19]->min_deadline 626200 --> 675057, now=674057

I0723 12:47:23.259599000 123145438097408 timer_generic.cc:533]           .. shard[18]: heap_empty=true

I0723 12:47:23.259604000 123145438097408 timer_generic.cc:508]           .. shard[18]->queue_deadline_cap --> 675056

I0723 12:47:23.259615000 123145435414528 completion_queue.cc:1386]     grpc_completion_queue_shutdown(cq=0x104700290)

I0723 12:47:23.259780000 123145438097408 timer_generic.cc:573]           .. shard[18] popped 0

D0723 12:47:23.259789000 123145435414528 completion_queue.cc:1091]     CQ:0x104700290   ref 1 -> 2 shutting_down

I0723 12:47:23.259798000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[18]->min_deadline 626200 --> 675057, now=674057

D0723 12:47:23.259806000 123145435414528 completion_queue.cc:1095]     CQ:0x104700290 unref 2 -> 1 shutting_down

I0723 12:47:23.259811000 123145438097408 timer_generic.cc:533]           .. shard[17]: heap_empty=true

I0723 12:47:23.259815000 123145438097408 timer_generic.cc:508]           .. shard[17]->queue_deadline_cap --> 675056

I0723 12:47:23.259816000 123145435414528 completion_queue.cc:959]      grpc_completion_queue_next(cq=0x104700290, deadline=gpr_timespec { tv_sec: 679, tv_nsec: 69205149, clock_type: 0 }, reserved=0x0)

D0723 12:47:23.272030000 123145435414528 completion_queue.cc:937]      PENDING TAGS:

D0723 12:47:23.272046000 123145435414528 completion_queue.cc:964]      CQ:0x104700290   ref 1 -> 2 next

I0723 12:47:23.272054000 123145435414528 completion_queue.cc:1059]     RETURN_EVENT[0x104700290]: QUEUE_SHUTDOWN

I0723 12:47:23.259819000 123145438097408 timer_generic.cc:573]           .. shard[17] popped 0

D0723 12:47:23.272059000 123145435414528 completion_queue.cc:1060]     CQ:0x104700290 unref 2 -> 1 next

I0723 12:47:23.272073000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[17]->min_deadline 626200 --> 675057, now=674057

I0723 12:47:23.272087000 123145435414528 completion_queue.cc:1392]     grpc_completion_queue_destroy(cq=0x104700290)

I0723 12:47:23.272092000 123145438097408 timer_generic.cc:533]           .. shard[15]: heap_empty=true

I0723 12:47:23.272093000 123145435414528 completion_queue.cc:1386]     grpc_completion_queue_shutdown(cq=0x104700290)

I0723 12:47:23.272100000 123145438097408 timer_generic.cc:508]           .. shard[15]->queue_deadline_cap --> 675056

D0723 12:47:23.272106000 123145435414528 completion_queue.cc:1091]     CQ:0x104700290   ref 1 -> 2 shutting_down

D0723 12:47:23.272249000 123145435414528 completion_queue.cc:1095]     CQ:0x104700290 unref 2 -> 1 shutting_down

D0723 12:47:23.272263000 123145435414528 completion_queue.cc:1396]     CQ:0x104700290 unref 1 -> 0 destroy

I0723 12:47:23.272237000 123145438097408 timer_generic.cc:573]           .. shard[15] popped 0

I0723 12:47:23.272270000 123145435414528 ev_posix.cc:312]              (polling-api) pollset_destroy(0x104700398)

I0723 12:47:23.272284000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[15]->min_deadline 626200 --> 675057, now=674057

I0723 12:47:23.272304000 123145438097408 timer_generic.cc:533]           .. shard[12]: heap_empty=true

I0723 12:47:23.272305000 123145435414528 metadata_array.cc:34]         grpc_metadata_array_destroy(array=0x60000021e920)

I0723 12:47:23.272311000 123145438097408 timer_generic.cc:508]           .. shard[12]->queue_deadline_cap --> 675056

I0723 12:47:23.272319000 123145435414528 metadata_array.cc:29]         grpc_metadata_array_init(array=0x600003020010)

I0723 12:47:23.273143000 123145435414528 call_details.cc:31]           grpc_call_details_init(cd=0x600003020028)

I0723 12:47:23.273122000 123145438097408 timer_generic.cc:573]           .. shard[12] popped 0

I0723 12:47:23.273166000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[12]->min_deadline 626200 --> 675057, now=674057

I0723 12:47:23.273153000 123145435414528 completion_queue.cc:481]      grpc_completion_queue_create_internal(completion_type=0, polling_type=0)

I0723 12:47:23.273175000 123145438097408 timer_generic.cc:533]           .. shard[11]: heap_empty=true

I0723 12:47:23.273187000 123145435414528 ev_posix.cc:302]              (polling-api) pollset_init(0x10150ff28)

I0723 12:47:23.273192000 123145438097408 timer_generic.cc:508]           .. shard[11]->queue_deadline_cap --> 675056

I0723 12:47:23.273201000 123145435414528 metadata_array.cc:29]         grpc_metadata_array_init(array=0x60000448ac40)

I0723 12:47:23.273344000 123145438097408 timer_generic.cc:573]           .. shard[11] popped 0

I0723 12:47:23.273363000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[11]->min_deadline 626200 --> 675057, now=674057

I0723 12:47:23.273369000 123145438097408 timer_generic.cc:533]           .. shard[10]: heap_empty=true

I0723 12:47:23.273373000 123145438097408 timer_generic.cc:508]           .. shard[10]->queue_deadline_cap --> 675056

I0723 12:47:23.273377000 123145438097408 timer_generic.cc:573]           .. shard[10] popped 0

I0723 12:47:23.273381000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[10]->min_deadline 626200 --> 675057, now=674057

I0723 12:47:23.273380000 123145435414528 server.cc:1487]               grpc_server_request_call(server=0x1017045a0, call=0x600003020088, details=0x600003020028, initial_metadata=0x60000448ac40, cq_bound_to_call=0x10150fe20, cq_for_notification=0x101705ed0, tag=0x65)

I0723 12:47:23.273387000 123145438097408 timer_generic.cc:533]           .. shard[9]: heap_empty=true

I0723 12:47:23.273574000 123145435414528 completion_queue.cc:959]      grpc_completion_queue_next(cq=0x101705ed0, deadline=gpr_timespec { tv_sec: 1274, tv_nsec: 82952209, clock_type: 0 }, reserved=0x0)

I0723 12:47:23.273566000 123145438097408 timer_generic.cc:508]           .. shard[9]->queue_deadline_cap --> 675056

I0723 12:47:23.273604000 123145438097408 timer_generic.cc:573]           .. shard[9] popped 0

D0723 12:47:23.273592000 123145435414528 completion_queue.cc:937]      PENDING TAGS: 0x65 0x65

I0723 12:47:23.273610000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[9]->min_deadline 626200 --> 675057, now=674057

D0723 12:47:23.273622000 123145435414528 completion_queue.cc:964]      CQ:0x101705ed0   ref 3 -> 4 next

I0723 12:47:23.273634000 123145438097408 timer_generic.cc:533]           .. shard[8]: heap_empty=true

I0723 12:47:23.273643000 123145435414528 ev_posix.cc:320]              (polling-api) pollset_work(0x101705fd8, 1274083) begin

I0723 12:47:23.273768000 123145438097408 timer_generic.cc:508]           .. shard[8]->queue_deadline_cap --> 675056

I0723 12:47:23.273786000 123145438097408 timer_generic.cc:573]           .. shard[8] popped 0

I0723 12:47:23.273792000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[8]->min_deadline 626200 --> 675057, now=674057

I0723 12:47:23.273796000 123145438097408 timer_generic.cc:533]           .. shard[7]: heap_empty=true

I0723 12:47:23.273800000 123145438097408 timer_generic.cc:508]           .. shard[7]->queue_deadline_cap --> 675056

D0723 12:47:23.273798000 123145435414528 ev_poll_posix.cc:371]         FD 5 0x600003b18000   ref 2 3 -> 5 [multipoller_start; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1043]

I0723 12:47:23.273807000 123145438097408 timer_generic.cc:573]           .. shard[7] popped 0

D0723 12:47:23.273820000 123145435414528 ev_poll_posix.cc:371]         FD 6 0x600003b100e0   ref 2 3 -> 5 [multipoller_start; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1043]

I0723 12:47:23.274011000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[7]->min_deadline 626200 --> 675057, now=674057

I0723 12:47:23.274030000 123145438097408 timer_generic.cc:533]           .. shard[6]: heap_empty=true

I0723 12:47:23.274035000 123145438097408 timer_generic.cc:508]           .. shard[6]->queue_deadline_cap --> 675056

I0723 12:47:23.274039000 123145438097408 timer_generic.cc:573]           .. shard[6] popped 0

D0723 12:47:23.274023000 123145435414528 ev_poll_posix.cc:371]         FD 5 0x600003b18000   ref 2 5 -> 7 [poll; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:647]

I0723 12:47:23.274045000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[6]->min_deadline 626200 --> 675057, now=674057

I0723 12:47:23.274233000 123145438097408 timer_generic.cc:533]           .. shard[5]: heap_empty=true

I0723 12:47:23.274243000 123145438097408 timer_generic.cc:508]           .. shard[5]->queue_deadline_cap --> 675056

I0723 12:47:23.274247000 123145438097408 timer_generic.cc:573]           .. shard[5] popped 0

I0723 12:47:23.274252000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[5]->min_deadline 626200 --> 675057, now=674057

I0723 12:47:23.274256000 123145438097408 timer_generic.cc:533]           .. shard[4]: heap_empty=true

I0723 12:47:23.274259000 123145438097408 timer_generic.cc:508]           .. shard[4]->queue_deadline_cap --> 675056

I0723 12:47:23.274279000 123145438097408 timer_generic.cc:573]           .. shard[4] popped 0

I0723 12:47:23.274291000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[4]->min_deadline 626200 --> 675057, now=674057

I0723 12:47:23.274297000 123145438097408 timer_generic.cc:533]           .. shard[3]: heap_empty=true

D0723 12:47:23.274056000 123145435414528 ev_poll_posix.cc:388]         FD 5 0x600003b18000 unref 2 7 -> 5 [multipoller_start; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1056]

I0723 12:47:23.274461000 123145438097408 timer_generic.cc:508]           .. shard[3]->queue_deadline_cap --> 675056

D0723 12:47:23.274488000 123145435414528 ev_poll_posix.cc:371]         FD 6 0x600003b100e0   ref 2 5 -> 7 [poll; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:647]

D0723 12:47:23.274506000 123145435414528 ev_poll_posix.cc:388]         FD 6 0x600003b100e0 unref 2 7 -> 5 [multipoller_start; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1056]

I0723 12:47:23.274488000 123145438097408 timer_generic.cc:573]           .. shard[3] popped 0

I0723 12:47:23.274527000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[3]->min_deadline 626200 --> 675057, now=674057

I0723 12:47:23.274651000 123145438097408 timer_generic.cc:533]           .. shard[2]: heap_empty=true

I0723 12:47:23.274661000 123145438097408 timer_generic.cc:508]           .. shard[2]->queue_deadline_cap --> 675056

I0723 12:47:23.274665000 123145438097408 timer_generic.cc:573]           .. shard[2] popped 0

I0723 12:47:23.274670000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[2]->min_deadline 626200 --> 675057, now=674057

I0723 12:47:23.274690000 123145438097408 timer_generic.cc:533]           .. shard[1]: heap_empty=true

I0723 12:47:23.274704000 123145438097408 timer_generic.cc:508]           .. shard[1]->queue_deadline_cap --> 675056

I0723 12:47:23.274725000 123145438097408 timer_generic.cc:573]           .. shard[1] popped 0

I0723 12:47:23.274739000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[1]->min_deadline 626200 --> 675057, now=674057

I0723 12:47:23.274747000 123145438097408 timer_generic.cc:533]           .. shard[0]: heap_empty=true

I0723 12:47:23.274817000 123145438097408 timer_generic.cc:508]           .. shard[0]->queue_deadline_cap --> 675056

I0723 12:47:23.274840000 123145438097408 timer_generic.cc:573]           .. shard[0] popped 0

I0723 12:47:23.274847000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[0]->min_deadline 626200 --> 675057, now=674057

I0723 12:47:23.274854000 123145438097408 timer_generic.cc:533]           .. shard[22]: heap_empty=true

I0723 12:47:23.274857000 123145438097408 timer_generic.cc:508]           .. shard[22]->queue_deadline_cap --> 675057

I0723 12:47:23.274861000 123145438097408 timer_generic.cc:573]           .. shard[22] popped 0

I0723 12:47:23.274865000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[22]->min_deadline 626211 --> 675058, now=674057

I0723 12:47:23.274869000 123145438097408 timer_generic.cc:533]           .. shard[14]: heap_empty=true

I0723 12:47:23.274872000 123145438097408 timer_generic.cc:508]           .. shard[14]->queue_deadline_cap --> 675057

I0723 12:47:23.275031000 123145438097408 timer_generic.cc:573]           .. shard[14] popped 0

I0723 12:47:23.275045000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[14]->min_deadline 626211 --> 675058, now=674057

I0723 12:47:23.275050000 123145438097408 timer_generic.cc:533]           .. shard[16]: heap_empty=true

I0723 12:47:23.275054000 123145438097408 timer_generic.cc:508]           .. shard[16]->queue_deadline_cap --> 675057

I0723 12:47:23.275058000 123145438097408 timer_generic.cc:573]           .. shard[16] popped 0

I0723 12:47:23.275062000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[16]->min_deadline 626211 --> 675058, now=674057

I0723 12:47:23.275065000 123145438097408 timer_generic.cc:533]           .. shard[13]: heap_empty=true

I0723 12:47:23.275069000 123145438097408 timer_generic.cc:508]           .. shard[13]->queue_deadline_cap --> 675057

I0723 12:47:23.275072000 123145438097408 timer_generic.cc:573]           .. shard[13] popped 0

I0723 12:47:23.275284000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[13]->min_deadline 626211 --> 675058, now=674057

I0723 12:47:23.275295000 123145438097408 timer_generic.cc:738]         TIMER CHECK END: r=1; next=675057

I0723 12:47:23.275301000 123145438097408 timer_manager.cc:194]         sleep for a 1000 milliseconds

I0723 12:47:24.250808000 123145438097408 timer_manager.cc:214]         wait ended: was_timed:1 kicked:0

I0723 12:47:24.250848000 123145438097408 timer_generic.cc:715]         TIMER CHECK BEGIN: now=675060 next=9223372036854775807 tls_min=626200 glob_min=675057

I0723 12:47:24.250857000 123145438097408 timer_generic.cc:610]           .. shard[0]->min_deadline = 675057

I0723 12:47:24.250863000 123145438097408 timer_generic.cc:533]           .. shard[0]: heap_empty=true

I0723 12:47:24.250869000 123145438097408 timer_generic.cc:508]           .. shard[0]->queue_deadline_cap --> 676059

I0723 12:47:24.250874000 123145438097408 timer_generic.cc:573]           .. shard[0] popped 0

I0723 12:47:24.250880000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[0]->min_deadline 675057 --> 676060, now=675060

I0723 12:47:24.250887000 123145438097408 timer_generic.cc:533]           .. shard[1]: heap_empty=true

I0723 12:47:24.250892000 123145438097408 timer_generic.cc:508]           .. shard[1]->queue_deadline_cap --> 676059

I0723 12:47:24.250976000 123145438097408 timer_generic.cc:573]           .. shard[1] popped 0

I0723 12:47:24.250992000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[1]->min_deadline 675057 --> 676060, now=675060

I0723 12:47:24.251000000 123145438097408 timer_generic.cc:533]           .. shard[2]: heap_empty=true

I0723 12:47:24.251006000 123145438097408 timer_generic.cc:508]           .. shard[2]->queue_deadline_cap --> 676059

I0723 12:47:24.251011000 123145438097408 timer_generic.cc:573]           .. shard[2] popped 0

I0723 12:47:24.251016000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[2]->min_deadline 675057 --> 676060, now=675060

I0723 12:47:24.251022000 123145438097408 timer_generic.cc:533]           .. shard[3]: heap_empty=true

I0723 12:47:24.251027000 123145438097408 timer_generic.cc:508]           .. shard[3]->queue_deadline_cap --> 676059

I0723 12:47:24.251031000 123145438097408 timer_generic.cc:573]           .. shard[3] popped 0

I0723 12:47:24.251037000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[3]->min_deadline 675057 --> 676060, now=675060

I0723 12:47:24.251445000 123145438097408 timer_generic.cc:533]           .. shard[4]: heap_empty=true

I0723 12:47:24.251460000 123145438097408 timer_generic.cc:508]           .. shard[4]->queue_deadline_cap --> 676059

I0723 12:47:24.251466000 123145438097408 timer_generic.cc:573]           .. shard[4] popped 0

I0723 12:47:24.251473000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[4]->min_deadline 675057 --> 676060, now=675060

I0723 12:47:24.251478000 123145438097408 timer_generic.cc:533]           .. shard[5]: heap_empty=true

I0723 12:47:24.251483000 123145438097408 timer_generic.cc:508]           .. shard[5]->queue_deadline_cap --> 676059

I0723 12:47:24.251488000 123145438097408 timer_generic.cc:573]           .. shard[5] popped 0

I0723 12:47:24.251494000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[5]->min_deadline 675057 --> 676060, now=675060

I0723 12:47:24.264144000 123145438097408 timer_generic.cc:533]           .. shard[6]: heap_empty=true

I0723 12:47:24.264181000 123145438097408 timer_generic.cc:508]           .. shard[6]->queue_deadline_cap --> 676059

I0723 12:47:24.264188000 123145438097408 timer_generic.cc:573]           .. shard[6] popped 0

I0723 12:47:24.264194000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[6]->min_deadline 675057 --> 676060, now=675060

I0723 12:47:24.264200000 123145438097408 timer_generic.cc:533]           .. shard[7]: heap_empty=true

I0723 12:47:24.264204000 123145438097408 timer_generic.cc:508]           .. shard[7]->queue_deadline_cap --> 676059

I0723 12:47:24.264208000 123145438097408 timer_generic.cc:573]           .. shard[7] popped 0

I0723 12:47:24.264213000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[7]->min_deadline 675057 --> 676060, now=675060

I0723 12:47:24.264218000 123145438097408 timer_generic.cc:533]           .. shard[8]: heap_empty=true

I0723 12:47:24.264404000 123145438097408 timer_generic.cc:508]           .. shard[8]->queue_deadline_cap --> 676059

I0723 12:47:24.264420000 123145438097408 timer_generic.cc:573]           .. shard[8] popped 0

I0723 12:47:24.264428000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[8]->min_deadline 675057 --> 676060, now=675060

I0723 12:47:24.264434000 123145438097408 timer_generic.cc:533]           .. shard[9]: heap_empty=true

I0723 12:47:24.264438000 123145438097408 timer_generic.cc:508]           .. shard[9]->queue_deadline_cap --> 676059

I0723 12:47:24.264443000 123145438097408 timer_generic.cc:573]           .. shard[9] popped 0

I0723 12:47:24.264448000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[9]->min_deadline 675057 --> 676060, now=675060

I0723 12:47:24.264453000 123145438097408 timer_generic.cc:533]           .. shard[10]: heap_empty=true

I0723 12:47:24.264457000 123145438097408 timer_generic.cc:508]           .. shard[10]->queue_deadline_cap --> 676059

I0723 12:47:24.264714000 123145438097408 timer_generic.cc:573]           .. shard[10] popped 0

I0723 12:47:24.264729000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[10]->min_deadline 675057 --> 676060, now=675060

I0723 12:47:24.264735000 123145438097408 timer_generic.cc:533]           .. shard[11]: heap_empty=true

I0723 12:47:24.264740000 123145438097408 timer_generic.cc:508]           .. shard[11]->queue_deadline_cap --> 676059

I0723 12:47:24.264745000 123145438097408 timer_generic.cc:573]           .. shard[11] popped 0

I0723 12:47:24.264750000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[11]->min_deadline 675057 --> 676060, now=675060

I0723 12:47:24.264754000 123145438097408 timer_generic.cc:533]           .. shard[12]: heap_empty=true

I0723 12:47:24.264759000 123145438097408 timer_generic.cc:508]           .. shard[12]->queue_deadline_cap --> 676059

I0723 12:47:24.264763000 123145438097408 timer_generic.cc:573]           .. shard[12] popped 0

I0723 12:47:24.264989000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[12]->min_deadline 675057 --> 676060, now=675060

I0723 12:47:24.265003000 123145438097408 timer_generic.cc:533]           .. shard[15]: heap_empty=true

I0723 12:47:24.265009000 123145438097408 timer_generic.cc:508]           .. shard[15]->queue_deadline_cap --> 676059

I0723 12:47:24.265014000 123145438097408 timer_generic.cc:573]           .. shard[15] popped 0

I0723 12:47:24.265019000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[15]->min_deadline 675057 --> 676060, now=675060

I0723 12:47:24.265024000 123145438097408 timer_generic.cc:533]           .. shard[17]: heap_empty=true

I0723 12:47:24.265028000 123145438097408 timer_generic.cc:508]           .. shard[17]->queue_deadline_cap --> 676059

I0723 12:47:24.265032000 123145438097408 timer_generic.cc:573]           .. shard[17] popped 0

I0723 12:47:24.265037000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[17]->min_deadline 675057 --> 676060, now=675060

I0723 12:47:24.265231000 123145438097408 timer_generic.cc:533]           .. shard[18]: heap_empty=true

I0723 12:47:24.265271000 123145438097408 timer_generic.cc:508]           .. shard[18]->queue_deadline_cap --> 676059

I0723 12:47:24.265278000 123145438097408 timer_generic.cc:573]           .. shard[18] popped 0

I0723 12:47:24.265284000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[18]->min_deadline 675057 --> 676060, now=675060

I0723 12:47:24.265290000 123145438097408 timer_generic.cc:533]           .. shard[19]: heap_empty=true

I0723 12:47:24.265294000 123145438097408 timer_generic.cc:508]           .. shard[19]->queue_deadline_cap --> 676059

I0723 12:47:24.265298000 123145438097408 timer_generic.cc:573]           .. shard[19] popped 0

I0723 12:47:24.265303000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[19]->min_deadline 675057 --> 676060, now=675060

I0723 12:47:24.265308000 123145438097408 timer_generic.cc:533]           .. shard[20]: heap_empty=true

I0723 12:47:24.265507000 123145438097408 timer_generic.cc:508]           .. shard[20]->queue_deadline_cap --> 676059

I0723 12:47:24.265520000 123145438097408 timer_generic.cc:573]           .. shard[20] popped 0

I0723 12:47:24.265527000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[20]->min_deadline 675057 --> 676060, now=675060

I0723 12:47:24.265532000 123145438097408 timer_generic.cc:533]           .. shard[21]: heap_empty=true

I0723 12:47:24.265537000 123145438097408 timer_generic.cc:508]           .. shard[21]->queue_deadline_cap --> 676059

I0723 12:47:24.265542000 123145438097408 timer_generic.cc:573]           .. shard[21] popped 0

I0723 12:47:24.265546000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[21]->min_deadline 675057 --> 676060, now=675060

I0723 12:47:24.265551000 123145438097408 timer_generic.cc:533]           .. shard[23]: heap_empty=true

I0723 12:47:24.265555000 123145438097408 timer_generic.cc:508]           .. shard[23]->queue_deadline_cap --> 676059

I0723 12:47:24.265766000 123145438097408 timer_generic.cc:573]           .. shard[23] popped 0

I0723 12:47:24.265780000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[23]->min_deadline 675057 --> 676060, now=675060

I0723 12:47:24.265789000 123145438097408 timer_generic.cc:533]           .. shard[13]: heap_empty=true

I0723 12:47:24.265794000 123145438097408 timer_generic.cc:508]           .. shard[13]->queue_deadline_cap --> 676060

I0723 12:47:24.265799000 123145438097408 timer_generic.cc:573]           .. shard[13] popped 0

I0723 12:47:24.265804000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[13]->min_deadline 675058 --> 676061, now=675060

I0723 12:47:24.265809000 123145438097408 timer_generic.cc:533]           .. shard[16]: heap_empty=true

I0723 12:47:24.265813000 123145438097408 timer_generic.cc:508]           .. shard[16]->queue_deadline_cap --> 676060

I0723 12:47:24.265818000 123145438097408 timer_generic.cc:573]           .. shard[16] popped 0

I0723 12:47:24.266014000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[16]->min_deadline 675058 --> 676061, now=675060

I0723 12:47:24.266029000 123145438097408 timer_generic.cc:533]           .. shard[14]: heap_empty=true

I0723 12:47:24.266035000 123145438097408 timer_generic.cc:508]           .. shard[14]->queue_deadline_cap --> 676060

I0723 12:47:24.266040000 123145438097408 timer_generic.cc:573]           .. shard[14] popped 0

I0723 12:47:24.266045000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[14]->min_deadline 675058 --> 676061, now=675060

I0723 12:47:24.266051000 123145438097408 timer_generic.cc:533]           .. shard[22]: heap_empty=true

I0723 12:47:24.266055000 123145438097408 timer_generic.cc:508]           .. shard[22]->queue_deadline_cap --> 676060

I0723 12:47:24.266059000 123145438097408 timer_generic.cc:573]           .. shard[22] popped 0

I0723 12:47:24.266064000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[22]->min_deadline 675058 --> 676061, now=675060

I0723 12:47:24.266310000 123145438097408 timer_generic.cc:738]         TIMER CHECK END: r=1; next=676060

I0723 12:47:24.266323000 123145438097408 timer_manager.cc:194]         sleep for a 1000 milliseconds

I0723 12:47:25.255245000 123145438097408 timer_manager.cc:214]         wait ended: was_timed:1 kicked:0

I0723 12:47:25.255284000 123145438097408 timer_generic.cc:715]         TIMER CHECK BEGIN: now=676064 next=9223372036854775807 tls_min=675057 glob_min=676060

I0723 12:47:25.255292000 123145438097408 timer_generic.cc:610]           .. shard[23]->min_deadline = 676060

I0723 12:47:25.255297000 123145438097408 timer_generic.cc:533]           .. shard[23]: heap_empty=true

I0723 12:47:25.255301000 123145438097408 timer_generic.cc:508]           .. shard[23]->queue_deadline_cap --> 677063

I0723 12:47:25.255304000 123145438097408 timer_generic.cc:573]           .. shard[23] popped 0

I0723 12:47:25.255308000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[23]->min_deadline 676060 --> 677064, now=676064

I0723 12:47:25.255313000 123145438097408 timer_generic.cc:533]           .. shard[21]: heap_empty=true

I0723 12:47:25.255316000 123145438097408 timer_generic.cc:508]           .. shard[21]->queue_deadline_cap --> 677063

I0723 12:47:25.255320000 123145438097408 timer_generic.cc:573]           .. shard[21] popped 0

I0723 12:47:25.255323000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[21]->min_deadline 676060 --> 677064, now=676064

I0723 12:47:25.255326000 123145438097408 timer_generic.cc:533]           .. shard[20]: heap_empty=true

I0723 12:47:25.255329000 123145438097408 timer_generic.cc:508]           .. shard[20]->queue_deadline_cap --> 677063

I0723 12:47:25.255624000 123145438097408 timer_generic.cc:573]           .. shard[20] popped 0

I0723 12:47:25.255639000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[20]->min_deadline 676060 --> 677064, now=676064

I0723 12:47:25.255646000 123145438097408 timer_generic.cc:533]           .. shard[19]: heap_empty=true

I0723 12:47:25.255665000 123145438097408 timer_generic.cc:508]           .. shard[19]->queue_deadline_cap --> 677063

I0723 12:47:25.255671000 123145438097408 timer_generic.cc:573]           .. shard[19] popped 0

I0723 12:47:25.255676000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[19]->min_deadline 676060 --> 677064, now=676064

I0723 12:47:25.255680000 123145438097408 timer_generic.cc:533]           .. shard[18]: heap_empty=true

I0723 12:47:25.255684000 123145438097408 timer_generic.cc:508]           .. shard[18]->queue_deadline_cap --> 677063

I0723 12:47:25.255687000 123145438097408 timer_generic.cc:573]           .. shard[18] popped 0

I0723 12:47:25.255690000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[18]->min_deadline 676060 --> 677064, now=676064

I0723 12:47:25.261787000 123145438097408 timer_generic.cc:533]           .. shard[17]: heap_empty=true

I0723 12:47:25.261803000 123145438097408 timer_generic.cc:508]           .. shard[17]->queue_deadline_cap --> 677063

I0723 12:47:25.261808000 123145438097408 timer_generic.cc:573]           .. shard[17] popped 0

I0723 12:47:25.261813000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[17]->min_deadline 676060 --> 677064, now=676064

I0723 12:47:25.261817000 123145438097408 timer_generic.cc:533]           .. shard[15]: heap_empty=true

I0723 12:47:25.261820000 123145438097408 timer_generic.cc:508]           .. shard[15]->queue_deadline_cap --> 677063

I0723 12:47:25.261823000 123145438097408 timer_generic.cc:573]           .. shard[15] popped 0

I0723 12:47:25.261827000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[15]->min_deadline 676060 --> 677064, now=676064

I0723 12:47:25.262024000 123145438097408 timer_generic.cc:533]           .. shard[12]: heap_empty=true

I0723 12:47:25.262033000 123145438097408 timer_generic.cc:508]           .. shard[12]->queue_deadline_cap --> 677063

I0723 12:47:25.262039000 123145438097408 timer_generic.cc:573]           .. shard[12] popped 0

I0723 12:47:25.262045000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[12]->min_deadline 676060 --> 677064, now=676064

I0723 12:47:25.262051000 123145438097408 timer_generic.cc:533]           .. shard[11]: heap_empty=true

I0723 12:47:25.262056000 123145438097408 timer_generic.cc:508]           .. shard[11]->queue_deadline_cap --> 677063

I0723 12:47:25.262062000 123145438097408 timer_generic.cc:573]           .. shard[11] popped 0

I0723 12:47:25.262078000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[11]->min_deadline 676060 --> 677064, now=676064

I0723 12:47:25.262091000 123145438097408 timer_generic.cc:533]           .. shard[10]: heap_empty=true

I0723 12:47:25.262315000 123145438097408 timer_generic.cc:508]           .. shard[10]->queue_deadline_cap --> 677063

I0723 12:47:25.262329000 123145438097408 timer_generic.cc:573]           .. shard[10] popped 0

I0723 12:47:25.262337000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[10]->min_deadline 676060 --> 677064, now=676064

I0723 12:47:25.262344000 123145438097408 timer_generic.cc:533]           .. shard[9]: heap_empty=true

I0723 12:47:25.262350000 123145438097408 timer_generic.cc:508]           .. shard[9]->queue_deadline_cap --> 677063

I0723 12:47:25.262355000 123145438097408 timer_generic.cc:573]           .. shard[9] popped 0

I0723 12:47:25.262361000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[9]->min_deadline 676060 --> 677064, now=676064

I0723 12:47:25.262365000 123145438097408 timer_generic.cc:533]           .. shard[8]: heap_empty=true

I0723 12:47:25.262368000 123145438097408 timer_generic.cc:508]           .. shard[8]->queue_deadline_cap --> 677063

I0723 12:47:25.262586000 123145438097408 timer_generic.cc:573]           .. shard[8] popped 0

I0723 12:47:25.262618000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[8]->min_deadline 676060 --> 677064, now=676064

I0723 12:47:25.262627000 123145438097408 timer_generic.cc:533]           .. shard[7]: heap_empty=true

I0723 12:47:25.262631000 123145438097408 timer_generic.cc:508]           .. shard[7]->queue_deadline_cap --> 677063

I0723 12:47:25.262635000 123145438097408 timer_generic.cc:573]           .. shard[7] popped 0

I0723 12:47:25.262639000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[7]->min_deadline 676060 --> 677064, now=676064

I0723 12:47:25.262642000 123145438097408 timer_generic.cc:533]           .. shard[6]: heap_empty=true

I0723 12:47:25.262645000 123145438097408 timer_generic.cc:508]           .. shard[6]->queue_deadline_cap --> 677063

I0723 12:47:25.262649000 123145438097408 timer_generic.cc:573]           .. shard[6] popped 0

I0723 12:47:25.262719000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[6]->min_deadline 676060 --> 677064, now=676064

I0723 12:47:25.262731000 123145438097408 timer_generic.cc:533]           .. shard[5]: heap_empty=true

I0723 12:47:25.262738000 123145438097408 timer_generic.cc:508]           .. shard[5]->queue_deadline_cap --> 677063

I0723 12:47:25.262744000 123145438097408 timer_generic.cc:573]           .. shard[5] popped 0

I0723 12:47:25.262750000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[5]->min_deadline 676060 --> 677064, now=676064

I0723 12:47:25.262756000 123145438097408 timer_generic.cc:533]           .. shard[4]: heap_empty=true

I0723 12:47:25.262761000 123145438097408 timer_generic.cc:508]           .. shard[4]->queue_deadline_cap --> 677063

I0723 12:47:25.262766000 123145438097408 timer_generic.cc:573]           .. shard[4] popped 0

I0723 12:47:25.262771000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[4]->min_deadline 676060 --> 677064, now=676064

I0723 12:47:25.262936000 123145438097408 timer_generic.cc:533]           .. shard[3]: heap_empty=true

I0723 12:47:25.262955000 123145438097408 timer_generic.cc:508]           .. shard[3]->queue_deadline_cap --> 677063

I0723 12:47:25.262960000 123145438097408 timer_generic.cc:573]           .. shard[3] popped 0

I0723 12:47:25.262964000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[3]->min_deadline 676060 --> 677064, now=676064

I0723 12:47:25.262968000 123145438097408 timer_generic.cc:533]           .. shard[2]: heap_empty=true

I0723 12:47:25.262972000 123145438097408 timer_generic.cc:508]           .. shard[2]->queue_deadline_cap --> 677063

I0723 12:47:25.262975000 123145438097408 timer_generic.cc:573]           .. shard[2] popped 0

I0723 12:47:25.262979000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[2]->min_deadline 676060 --> 677064, now=676064

I0723 12:47:25.262982000 123145438097408 timer_generic.cc:533]           .. shard[1]: heap_empty=true

I0723 12:47:25.263190000 123145438097408 timer_generic.cc:508]           .. shard[1]->queue_deadline_cap --> 677063

I0723 12:47:25.263270000 123145438097408 timer_generic.cc:573]           .. shard[1] popped 0

I0723 12:47:25.263290000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[1]->min_deadline 676060 --> 677064, now=676064

I0723 12:47:25.263295000 123145438097408 timer_generic.cc:533]           .. shard[0]: heap_empty=true

I0723 12:47:25.263299000 123145438097408 timer_generic.cc:508]           .. shard[0]->queue_deadline_cap --> 677063

I0723 12:47:25.263303000 123145438097408 timer_generic.cc:573]           .. shard[0] popped 0

I0723 12:47:25.263306000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[0]->min_deadline 676060 --> 677064, now=676064

I0723 12:47:25.263310000 123145438097408 timer_generic.cc:533]           .. shard[22]: heap_empty=true

I0723 12:47:25.263313000 123145438097408 timer_generic.cc:508]           .. shard[22]->queue_deadline_cap --> 677064

I0723 12:47:25.263457000 123145438097408 timer_generic.cc:573]           .. shard[22] popped 0

I0723 12:47:25.263470000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[22]->min_deadline 676061 --> 677065, now=676064

I0723 12:47:25.263475000 123145438097408 timer_generic.cc:533]           .. shard[14]: heap_empty=true

I0723 12:47:25.263479000 123145438097408 timer_generic.cc:508]           .. shard[14]->queue_deadline_cap --> 677064

I0723 12:47:25.263482000 123145438097408 timer_generic.cc:573]           .. shard[14] popped 0

I0723 12:47:25.263486000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[14]->min_deadline 676061 --> 677065, now=676064

I0723 12:47:25.263490000 123145438097408 timer_generic.cc:533]           .. shard[16]: heap_empty=true

I0723 12:47:25.263493000 123145438097408 timer_generic.cc:508]           .. shard[16]->queue_deadline_cap --> 677064

I0723 12:47:25.263496000 123145438097408 timer_generic.cc:573]           .. shard[16] popped 0

I0723 12:47:25.263718000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[16]->min_deadline 676061 --> 677065, now=676064

I0723 12:47:25.263727000 123145438097408 timer_generic.cc:533]           .. shard[13]: heap_empty=true

I0723 12:47:25.263732000 123145438097408 timer_generic.cc:508]           .. shard[13]->queue_deadline_cap --> 677064

I0723 12:47:25.263736000 123145438097408 timer_generic.cc:573]           .. shard[13] popped 0

I0723 12:47:25.263740000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[13]->min_deadline 676061 --> 677065, now=676064

I0723 12:47:25.263744000 123145438097408 timer_generic.cc:738]         TIMER CHECK END: r=1; next=677064

I0723 12:47:25.263749000 123145438097408 timer_manager.cc:194]         sleep for a 1000 milliseconds

I0723 12:47:26.257656000 123145438097408 timer_manager.cc:214]         wait ended: was_timed:1 kicked:0

I0723 12:47:26.257681000 123145438097408 timer_generic.cc:715]         TIMER CHECK BEGIN: now=677066 next=9223372036854775807 tls_min=676060 glob_min=677064

I0723 12:47:26.257687000 123145438097408 timer_generic.cc:610]           .. shard[0]->min_deadline = 677064

I0723 12:47:26.257691000 123145438097408 timer_generic.cc:533]           .. shard[0]: heap_empty=true

I0723 12:47:26.257694000 123145438097408 timer_generic.cc:508]           .. shard[0]->queue_deadline_cap --> 678065

I0723 12:47:26.257697000 123145438097408 timer_generic.cc:573]           .. shard[0] popped 0

I0723 12:47:26.257702000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[0]->min_deadline 677064 --> 678066, now=677066

I0723 12:47:26.257705000 123145438097408 timer_generic.cc:533]           .. shard[1]: heap_empty=true

I0723 12:47:26.257709000 123145438097408 timer_generic.cc:508]           .. shard[1]->queue_deadline_cap --> 678065

I0723 12:47:26.257712000 123145438097408 timer_generic.cc:573]           .. shard[1] popped 0

I0723 12:47:26.257715000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[1]->min_deadline 677064 --> 678066, now=677066

I0723 12:47:26.257718000 123145438097408 timer_generic.cc:533]           .. shard[2]: heap_empty=true

I0723 12:47:26.257721000 123145438097408 timer_generic.cc:508]           .. shard[2]->queue_deadline_cap --> 678065

I0723 12:47:26.257724000 123145438097408 timer_generic.cc:573]           .. shard[2] popped 0

I0723 12:47:26.257727000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[2]->min_deadline 677064 --> 678066, now=677066

I0723 12:47:26.257990000 123145438097408 timer_generic.cc:533]           .. shard[3]: heap_empty=true

I0723 12:47:26.257999000 123145438097408 timer_generic.cc:508]           .. shard[3]->queue_deadline_cap --> 678065

I0723 12:47:26.258002000 123145438097408 timer_generic.cc:573]           .. shard[3] popped 0

I0723 12:47:26.258006000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[3]->min_deadline 677064 --> 678066, now=677066

I0723 12:47:26.258010000 123145438097408 timer_generic.cc:533]           .. shard[4]: heap_empty=true

I0723 12:47:26.258013000 123145438097408 timer_generic.cc:508]           .. shard[4]->queue_deadline_cap --> 678065

I0723 12:47:26.258016000 123145438097408 timer_generic.cc:573]           .. shard[4] popped 0

I0723 12:47:26.258019000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[4]->min_deadline 677064 --> 678066, now=677066

I0723 12:47:26.264618000 123145438097408 timer_generic.cc:533]           .. shard[5]: heap_empty=true

I0723 12:47:26.264636000 123145438097408 timer_generic.cc:508]           .. shard[5]->queue_deadline_cap --> 678065

I0723 12:47:26.264641000 123145438097408 timer_generic.cc:573]           .. shard[5] popped 0

I0723 12:47:26.264647000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[5]->min_deadline 677064 --> 678066, now=677066

I0723 12:47:26.264652000 123145438097408 timer_generic.cc:533]           .. shard[6]: heap_empty=true

I0723 12:47:26.264656000 123145438097408 timer_generic.cc:508]           .. shard[6]->queue_deadline_cap --> 678065

I0723 12:47:26.264661000 123145438097408 timer_generic.cc:573]           .. shard[6] popped 0

I0723 12:47:26.264666000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[6]->min_deadline 677064 --> 678066, now=677066

I0723 12:47:26.264671000 123145438097408 timer_generic.cc:533]           .. shard[7]: heap_empty=true

I0723 12:47:26.264676000 123145438097408 timer_generic.cc:508]           .. shard[7]->queue_deadline_cap --> 678065

I0723 12:47:26.264839000 123145438097408 timer_generic.cc:573]           .. shard[7] popped 0

I0723 12:47:26.264850000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[7]->min_deadline 677064 --> 678066, now=677066

I0723 12:47:26.264856000 123145438097408 timer_generic.cc:533]           .. shard[8]: heap_empty=true

I0723 12:47:26.264861000 123145438097408 timer_generic.cc:508]           .. shard[8]->queue_deadline_cap --> 678065

I0723 12:47:26.264865000 123145438097408 timer_generic.cc:573]           .. shard[8] popped 0

I0723 12:47:26.264869000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[8]->min_deadline 677064 --> 678066, now=677066

I0723 12:47:26.264874000 123145438097408 timer_generic.cc:533]           .. shard[9]: heap_empty=true

I0723 12:47:26.264878000 123145438097408 timer_generic.cc:508]           .. shard[9]->queue_deadline_cap --> 678065

I0723 12:47:26.264881000 123145438097408 timer_generic.cc:573]           .. shard[9] popped 0

I0723 12:47:26.265068000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[9]->min_deadline 677064 --> 678066, now=677066

I0723 12:47:26.265085000 123145438097408 timer_generic.cc:533]           .. shard[10]: heap_empty=true

I0723 12:47:26.265096000 123145438097408 timer_generic.cc:508]           .. shard[10]->queue_deadline_cap --> 678065

I0723 12:47:26.265101000 123145438097408 timer_generic.cc:573]           .. shard[10] popped 0

I0723 12:47:26.265105000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[10]->min_deadline 677064 --> 678066, now=677066

I0723 12:47:26.265108000 123145438097408 timer_generic.cc:533]           .. shard[11]: heap_empty=true

I0723 12:47:26.265111000 123145438097408 timer_generic.cc:508]           .. shard[11]->queue_deadline_cap --> 678065

I0723 12:47:26.265113000 123145438097408 timer_generic.cc:573]           .. shard[11] popped 0

I0723 12:47:26.265116000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[11]->min_deadline 677064 --> 678066, now=677066

I0723 12:47:26.265235000 123145438097408 timer_generic.cc:533]           .. shard[12]: heap_empty=true

I0723 12:47:26.265242000 123145438097408 timer_generic.cc:508]           .. shard[12]->queue_deadline_cap --> 678065

I0723 12:47:26.265257000 123145438097408 timer_generic.cc:573]           .. shard[12] popped 0

I0723 12:47:26.265261000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[12]->min_deadline 677064 --> 678066, now=677066

I0723 12:47:26.265264000 123145438097408 timer_generic.cc:533]           .. shard[15]: heap_empty=true

I0723 12:47:26.265267000 123145438097408 timer_generic.cc:508]           .. shard[15]->queue_deadline_cap --> 678065

I0723 12:47:26.265270000 123145438097408 timer_generic.cc:573]           .. shard[15] popped 0

I0723 12:47:26.265273000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[15]->min_deadline 677064 --> 678066, now=677066

I0723 12:47:26.265363000 123145438097408 timer_generic.cc:533]           .. shard[17]: heap_empty=true

I0723 12:47:26.265370000 123145438097408 timer_generic.cc:508]           .. shard[17]->queue_deadline_cap --> 678065

I0723 12:47:26.265373000 123145438097408 timer_generic.cc:573]           .. shard[17] popped 0

I0723 12:47:26.265376000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[17]->min_deadline 677064 --> 678066, now=677066

I0723 12:47:26.265379000 123145438097408 timer_generic.cc:533]           .. shard[18]: heap_empty=true

I0723 12:47:26.265383000 123145438097408 timer_generic.cc:508]           .. shard[18]->queue_deadline_cap --> 678065

I0723 12:47:26.265396000 123145438097408 timer_generic.cc:573]           .. shard[18] popped 0

I0723 12:47:26.265399000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[18]->min_deadline 677064 --> 678066, now=677066

I0723 12:47:26.265402000 123145438097408 timer_generic.cc:533]           .. shard[19]: heap_empty=true

I0723 12:47:26.265564000 123145438097408 timer_generic.cc:508]           .. shard[19]->queue_deadline_cap --> 678065

I0723 12:47:26.265572000 123145438097408 timer_generic.cc:573]           .. shard[19] popped 0

I0723 12:47:26.265589000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[19]->min_deadline 677064 --> 678066, now=677066

I0723 12:47:26.265595000 123145438097408 timer_generic.cc:533]           .. shard[20]: heap_empty=true

I0723 12:47:26.265598000 123145438097408 timer_generic.cc:508]           .. shard[20]->queue_deadline_cap --> 678065

I0723 12:47:26.265600000 123145438097408 timer_generic.cc:573]           .. shard[20] popped 0

I0723 12:47:26.265603000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[20]->min_deadline 677064 --> 678066, now=677066

I0723 12:47:26.265606000 123145438097408 timer_generic.cc:533]           .. shard[21]: heap_empty=true

I0723 12:47:26.265608000 123145438097408 timer_generic.cc:508]           .. shard[21]->queue_deadline_cap --> 678065

I0723 12:47:26.265719000 123145438097408 timer_generic.cc:573]           .. shard[21] popped 0

I0723 12:47:26.265729000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[21]->min_deadline 677064 --> 678066, now=677066

I0723 12:47:26.265735000 123145438097408 timer_generic.cc:533]           .. shard[23]: heap_empty=true

I0723 12:47:26.265740000 123145438097408 timer_generic.cc:508]           .. shard[23]->queue_deadline_cap --> 678065

I0723 12:47:26.265744000 123145438097408 timer_generic.cc:573]           .. shard[23] popped 0

I0723 12:47:26.265748000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[23]->min_deadline 677064 --> 678066, now=677066

I0723 12:47:26.265760000 123145438097408 timer_generic.cc:533]           .. shard[13]: heap_empty=true

I0723 12:47:26.265765000 123145438097408 timer_generic.cc:508]           .. shard[13]->queue_deadline_cap --> 678066

I0723 12:47:26.265767000 123145438097408 timer_generic.cc:573]           .. shard[13] popped 0

I0723 12:47:26.265876000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[13]->min_deadline 677065 --> 678067, now=677066

I0723 12:47:26.265884000 123145438097408 timer_generic.cc:533]           .. shard[16]: heap_empty=true

I0723 12:47:26.265888000 123145438097408 timer_generic.cc:508]           .. shard[16]->queue_deadline_cap --> 678066

I0723 12:47:26.265903000 123145438097408 timer_generic.cc:573]           .. shard[16] popped 0

I0723 12:47:26.265908000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[16]->min_deadline 677065 --> 678067, now=677066

I0723 12:47:26.265911000 123145438097408 timer_generic.cc:533]           .. shard[14]: heap_empty=true

I0723 12:47:26.265913000 123145438097408 timer_generic.cc:508]           .. shard[14]->queue_deadline_cap --> 678066

I0723 12:47:26.265916000 123145438097408 timer_generic.cc:573]           .. shard[14] popped 0

I0723 12:47:26.265919000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[14]->min_deadline 677065 --> 678067, now=677066

I0723 12:47:26.266039000 123145438097408 timer_generic.cc:533]           .. shard[22]: heap_empty=true

I0723 12:47:26.266045000 123145438097408 timer_generic.cc:508]           .. shard[22]->queue_deadline_cap --> 678066

I0723 12:47:26.266050000 123145438097408 timer_generic.cc:573]           .. shard[22] popped 0

I0723 12:47:26.266055000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[22]->min_deadline 677065 --> 678067, now=677066

I0723 12:47:26.266061000 123145438097408 timer_generic.cc:738]         TIMER CHECK END: r=1; next=678066

I0723 12:47:26.266076000 123145438097408 timer_manager.cc:194]         sleep for a 1000 milliseconds

I0723 12:47:27.260613000 123145438097408 timer_manager.cc:214]         wait ended: was_timed:1 kicked:0

I0723 12:47:27.260637000 123145438097408 timer_generic.cc:715]         TIMER CHECK BEGIN: now=678069 next=9223372036854775807 tls_min=677064 glob_min=678066

I0723 12:47:27.260643000 123145438097408 timer_generic.cc:610]           .. shard[23]->min_deadline = 678066

I0723 12:47:27.260647000 123145438097408 timer_generic.cc:533]           .. shard[23]: heap_empty=true

I0723 12:47:27.260651000 123145438097408 timer_generic.cc:508]           .. shard[23]->queue_deadline_cap --> 679068

I0723 12:47:27.260655000 123145438097408 timer_generic.cc:573]           .. shard[23] popped 0

I0723 12:47:27.260659000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[23]->min_deadline 678066 --> 679069, now=678069

I0723 12:47:27.260664000 123145438097408 timer_generic.cc:533]           .. shard[21]: heap_empty=true

I0723 12:47:27.260667000 123145438097408 timer_generic.cc:508]           .. shard[21]->queue_deadline_cap --> 679068

I0723 12:47:27.260699000 123145438097408 timer_generic.cc:573]           .. shard[21] popped 0

I0723 12:47:27.260709000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[21]->min_deadline 678066 --> 679069, now=678069

I0723 12:47:27.260714000 123145438097408 timer_generic.cc:533]           .. shard[20]: heap_empty=true

I0723 12:47:27.260720000 123145438097408 timer_generic.cc:508]           .. shard[20]->queue_deadline_cap --> 679068

I0723 12:47:27.260725000 123145438097408 timer_generic.cc:573]           .. shard[20] popped 0

I0723 12:47:27.260731000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[20]->min_deadline 678066 --> 679069, now=678069

I0723 12:47:27.260735000 123145438097408 timer_generic.cc:533]           .. shard[19]: heap_empty=true

I0723 12:47:27.260738000 123145438097408 timer_generic.cc:508]           .. shard[19]->queue_deadline_cap --> 679068

I0723 12:47:27.260741000 123145438097408 timer_generic.cc:573]           .. shard[19] popped 0

I0723 12:47:27.260972000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[19]->min_deadline 678066 --> 679069, now=678069

I0723 12:47:27.260983000 123145438097408 timer_generic.cc:533]           .. shard[18]: heap_empty=true

I0723 12:47:27.260987000 123145438097408 timer_generic.cc:508]           .. shard[18]->queue_deadline_cap --> 679068

I0723 12:47:27.260991000 123145438097408 timer_generic.cc:573]           .. shard[18] popped 0

I0723 12:47:27.260995000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[18]->min_deadline 678066 --> 679069, now=678069

I0723 12:47:27.260998000 123145438097408 timer_generic.cc:533]           .. shard[17]: heap_empty=true

I0723 12:47:27.261002000 123145438097408 timer_generic.cc:508]           .. shard[17]->queue_deadline_cap --> 679068

I0723 12:47:27.261005000 123145438097408 timer_generic.cc:573]           .. shard[17] popped 0

I0723 12:47:27.261008000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[17]->min_deadline 678066 --> 679069, now=678069

I0723 12:47:27.268959000 123145438097408 timer_generic.cc:533]           .. shard[15]: heap_empty=true

I0723 12:47:27.268974000 123145438097408 timer_generic.cc:508]           .. shard[15]->queue_deadline_cap --> 679068

I0723 12:47:27.268979000 123145438097408 timer_generic.cc:573]           .. shard[15] popped 0

I0723 12:47:27.268984000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[15]->min_deadline 678066 --> 679069, now=678069

I0723 12:47:27.268988000 123145438097408 timer_generic.cc:533]           .. shard[12]: heap_empty=true

I0723 12:47:27.268993000 123145438097408 timer_generic.cc:508]           .. shard[12]->queue_deadline_cap --> 679068

I0723 12:47:27.268998000 123145438097408 timer_generic.cc:573]           .. shard[12] popped 0

I0723 12:47:27.269003000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[12]->min_deadline 678066 --> 679069, now=678069

I0723 12:47:27.269009000 123145438097408 timer_generic.cc:533]           .. shard[11]: heap_empty=true

I0723 12:47:27.269265000 123145438097408 timer_generic.cc:508]           .. shard[11]->queue_deadline_cap --> 679068

I0723 12:47:27.269276000 123145438097408 timer_generic.cc:573]           .. shard[11] popped 0

I0723 12:47:27.269282000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[11]->min_deadline 678066 --> 679069, now=678069

I0723 12:47:27.269286000 123145438097408 timer_generic.cc:533]           .. shard[10]: heap_empty=true

I0723 12:47:27.269290000 123145438097408 timer_generic.cc:508]           .. shard[10]->queue_deadline_cap --> 679068

I0723 12:47:27.269294000 123145438097408 timer_generic.cc:573]           .. shard[10] popped 0

I0723 12:47:27.269297000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[10]->min_deadline 678066 --> 679069, now=678069

I0723 12:47:27.269301000 123145438097408 timer_generic.cc:533]           .. shard[9]: heap_empty=true

I0723 12:47:27.269304000 123145438097408 timer_generic.cc:508]           .. shard[9]->queue_deadline_cap --> 679068

I0723 12:47:27.269532000 123145438097408 timer_generic.cc:573]           .. shard[9] popped 0

I0723 12:47:27.269541000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[9]->min_deadline 678066 --> 679069, now=678069

I0723 12:47:27.269545000 123145438097408 timer_generic.cc:533]           .. shard[8]: heap_empty=true

I0723 12:47:27.269549000 123145438097408 timer_generic.cc:508]           .. shard[8]->queue_deadline_cap --> 679068

I0723 12:47:27.269552000 123145438097408 timer_generic.cc:573]           .. shard[8] popped 0

I0723 12:47:27.269556000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[8]->min_deadline 678066 --> 679069, now=678069

I0723 12:47:27.269559000 123145438097408 timer_generic.cc:533]           .. shard[7]: heap_empty=true

I0723 12:47:27.269562000 123145438097408 timer_generic.cc:508]           .. shard[7]->queue_deadline_cap --> 679068

I0723 12:47:27.269568000 123145438097408 timer_generic.cc:573]           .. shard[7] popped 0

I0723 12:47:27.269690000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[7]->min_deadline 678066 --> 679069, now=678069

I0723 12:47:27.269698000 123145438097408 timer_generic.cc:533]           .. shard[6]: heap_empty=true

I0723 12:47:27.269703000 123145438097408 timer_generic.cc:508]           .. shard[6]->queue_deadline_cap --> 679068

I0723 12:47:27.269707000 123145438097408 timer_generic.cc:573]           .. shard[6] popped 0

I0723 12:47:27.269710000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[6]->min_deadline 678066 --> 679069, now=678069

I0723 12:47:27.269714000 123145438097408 timer_generic.cc:533]           .. shard[5]: heap_empty=true

I0723 12:47:27.269717000 123145438097408 timer_generic.cc:508]           .. shard[5]->queue_deadline_cap --> 679068

I0723 12:47:27.269720000 123145438097408 timer_generic.cc:573]           .. shard[5] popped 0

I0723 12:47:27.269724000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[5]->min_deadline 678066 --> 679069, now=678069

I0723 12:47:27.269877000 123145438097408 timer_generic.cc:533]           .. shard[4]: heap_empty=true

I0723 12:47:27.269882000 123145438097408 timer_generic.cc:508]           .. shard[4]->queue_deadline_cap --> 679068

I0723 12:47:27.269885000 123145438097408 timer_generic.cc:573]           .. shard[4] popped 0

I0723 12:47:27.269888000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[4]->min_deadline 678066 --> 679069, now=678069

I0723 12:47:27.269892000 123145438097408 timer_generic.cc:533]           .. shard[3]: heap_empty=true

I0723 12:47:27.269895000 123145438097408 timer_generic.cc:508]           .. shard[3]->queue_deadline_cap --> 679068

I0723 12:47:27.269898000 123145438097408 timer_generic.cc:573]           .. shard[3] popped 0

I0723 12:47:27.269902000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[3]->min_deadline 678066 --> 679069, now=678069

I0723 12:47:27.269905000 123145438097408 timer_generic.cc:533]           .. shard[2]: heap_empty=true

I0723 12:47:27.270097000 123145438097408 timer_generic.cc:508]           .. shard[2]->queue_deadline_cap --> 679068

I0723 12:47:27.270107000 123145438097408 timer_generic.cc:573]           .. shard[2] popped 0

I0723 12:47:27.270113000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[2]->min_deadline 678066 --> 679069, now=678069

I0723 12:47:27.270117000 123145438097408 timer_generic.cc:533]           .. shard[1]: heap_empty=true

I0723 12:47:27.270121000 123145438097408 timer_generic.cc:508]           .. shard[1]->queue_deadline_cap --> 679068

I0723 12:47:27.270124000 123145438097408 timer_generic.cc:573]           .. shard[1] popped 0

I0723 12:47:27.270128000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[1]->min_deadline 678066 --> 679069, now=678069

I0723 12:47:27.270131000 123145438097408 timer_generic.cc:533]           .. shard[0]: heap_empty=true

I0723 12:47:27.270135000 123145438097408 timer_generic.cc:508]           .. shard[0]->queue_deadline_cap --> 679068

I0723 12:47:27.270325000 123145438097408 timer_generic.cc:573]           .. shard[0] popped 0

I0723 12:47:27.270336000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[0]->min_deadline 678066 --> 679069, now=678069

I0723 12:47:27.270341000 123145438097408 timer_generic.cc:533]           .. shard[22]: heap_empty=true

I0723 12:47:27.270345000 123145438097408 timer_generic.cc:508]           .. shard[22]->queue_deadline_cap --> 679069

I0723 12:47:27.270350000 123145438097408 timer_generic.cc:573]           .. shard[22] popped 0

I0723 12:47:27.270356000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[22]->min_deadline 678067 --> 679070, now=678069

I0723 12:47:27.270362000 123145438097408 timer_generic.cc:533]           .. shard[14]: heap_empty=true

I0723 12:47:27.270367000 123145438097408 timer_generic.cc:508]           .. shard[14]->queue_deadline_cap --> 679069

I0723 12:47:27.270370000 123145438097408 timer_generic.cc:573]           .. shard[14] popped 0

I0723 12:47:27.270492000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[14]->min_deadline 678067 --> 679070, now=678069

I0723 12:47:27.270502000 123145438097408 timer_generic.cc:533]           .. shard[16]: heap_empty=true

I0723 12:47:27.270523000 123145438097408 timer_generic.cc:508]           .. shard[16]->queue_deadline_cap --> 679069

I0723 12:47:27.270528000 123145438097408 timer_generic.cc:573]           .. shard[16] popped 0

I0723 12:47:27.270533000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[16]->min_deadline 678067 --> 679070, now=678069

I0723 12:47:27.270537000 123145438097408 timer_generic.cc:533]           .. shard[13]: heap_empty=true

I0723 12:47:27.270540000 123145438097408 timer_generic.cc:508]           .. shard[13]->queue_deadline_cap --> 679069

I0723 12:47:27.270544000 123145438097408 timer_generic.cc:573]           .. shard[13] popped 0

I0723 12:47:27.270548000 123145438097408 timer_generic.cc:628]           .. result --> 1, shard[13]->min_deadline 678067 --> 679070, now=678069

I0723 12:47:27.270620000 123145438097408 timer_generic.cc:738]         TIMER CHECK END: r=1; next=679069

I0723 12:47:27.270632000 123145438097408 timer_manager.cc:194]         sleep for a 1000 milliseconds

I0723 12:47:28.173434000 123145435414528 ev_poll_posix.cc:1067]        0x101705fd8 poll=1

I0723 12:47:28.173468000 123145435414528 ev_poll_posix.cc:1101]        0x101705fd8 got_event: 5 r:1 w:0 [1]

D0723 12:47:28.173475000 123145435414528 ev_poll_posix.cc:388]         FD 5 0x600003b18000 unref 2 5 -> 3 [poll; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:740]

I0723 12:47:28.173478000 123145435414528 ev_poll_posix.cc:1101]        0x101705fd8 got_event: 6 r:0 w:0 [0]

D0723 12:47:28.173482000 123145435414528 ev_poll_posix.cc:388]         FD 6 0x600003b100e0 unref 2 5 -> 3 [poll; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:740]

D0723 12:47:28.173486000 123145435414528 exec_ctx.cc:34]               running closure 0x101607d18: created [/Pods/gRPC-Core/src/core/lib/iomgr/tcp_server_posix.cc:506]: scheduled [/Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:573]

I0723 12:47:28.173541000 123145435414528 tcp_server_posix.cc:226]      SERVER_CONNECT: incoming connection: ipv6:[::1]:64145

I0723 12:47:28.173546000 123145435414528 ev_posix.cc:252]              (polling-api) fd_create(9, tcp-server-connection:ipv6:[::1]:64145, 1)

I0723 12:47:28.173727000 123145435414528 ev_posix.cc:253]              (fd-trace) fd_create(9, tcp-server-connection:ipv6:[::1]:64145, 1)

I0723 12:47:28.173738000 123145435414528 ev_posix.cc:335]              (polling-api) pollset_add_fd(0x101705fd8, 9)

D0723 12:47:28.173743000 123145435414528 ev_poll_posix.cc:371]         FD 9 0x600003b04380   ref 2 1 -> 3 [multipoller; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:928]

I0723 12:47:28.173749000 123145435414528 combiner.cc:89]               C:0x600003d042d0 create

I0723 12:47:28.173756000 123145435414528 ev_posix.cc:350]              (polling-api) pollset_set_create(0x600003000b40)

I0723 12:47:28.173759000 123145435414528 ev_posix.cc:362]              (polling-api) pollset_set_add_pollset(0x600003000b40, 0x101705fd8)

I0723 12:47:28.173784000 123145435414528 timer_generic.cc:365]         TIMER 0x101320308: SET 798982 now 678982 call 0x101320340[0x100a70600]

I0723 12:47:28.177421000 123145435414528 timer_generic.cc:401]           .. add to shard 17 with queue_deadline_cap=679068 => is_first_timer=false

I0723 12:47:28.177438000 123145435414528 handshaker.cc:130]            handshake_manager 0x101320220: error="No Error" shutdown=0 index=0, args={endpoint=0x101336940, args=0x60000002c090 {size=0: }, read_buffer=0x1013207c0 (length=0), exit_early=0}

I0723 12:47:28.177459000 123145435414528 handshaker.cc:163]            handshake_manager 0x101320220: handshaking complete -- scheduling on_handshake_done with error="No Error"

I0723 12:47:28.177462000 123145435414528 timer_generic.cc:467]         TIMER 0x101320308: CANCEL pending=true

D0723 12:47:28.177469000 123145435414528 exec_ctx.cc:43]               closure 0x101607d18 finished

D0723 12:47:28.177474000 123145435414528 exec_ctx.cc:34]               running closure 0x101320340: created [/Pods/gRPC-Core/src/core/lib/channel/handshaker.cc:239]: scheduled [/Pods/gRPC-Core/src/core/lib/iomgr/timer_generic.cc:474]

D0723 12:47:28.177599000 123145435414528 exec_ctx.cc:43]               closure 0x101320340 finished

D0723 12:47:28.177640000 123145435414528 exec_ctx.cc:34]               running closure 0x101320390: created [/Pods/gRPC-Core/src/core/lib/channel/handshaker.cc:235]: scheduled [/Pods/gRPC-Core/src/core/lib/channel/handshaker.cc:171]

I0723 12:47:28.177665000 123145435414528 combiner.cc:89]               C:0x600003d043c0 create

I0723 12:47:28.177728000 123145435414528 ref_counted.h:98]             chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:453 ref 1 -> 2 init keepalive ping

I0723 12:47:28.177732000 123145435414528 timer_generic.cc:365]         TIMER 0x10180f570: SET 7878982 now 678982 call 0x10180f430[0x100a19fd0]

I0723 12:47:28.177834000 123145435414528 timer_generic.cc:401]           .. add to shard 14 with queue_deadline_cap=679069 => is_first_timer=false

I0723 12:47:28.177840000 123145435414528 ref_counted.h:98]             chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:546 ref 2 -> 3 bdp_ping

I0723 12:47:28.177843000 123145435414528 bdp_estimator.h:53]           bdp[ipv6:[::1]:64145]:sched acc=0 est=65536

I0723 12:47:28.177850000 123145435414528 chttp2_transport.cc:827]      W:0x10180da00 SERVER state IDLE -> WRITING [TRANSPORT_FLOW_CONTROL]

I0723 12:47:28.177854000 123145435414528 ref_counted.h:98]             chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:924 ref 3 -> 4 writing

I0723 12:47:28.177857000 123145435414528 combiner.cc:339]              C:0x600003d043c0 grpc_combiner_execute_finally c=0x10180dad0; ac=0x0

I0723 12:47:28.178047000 123145435414528 combiner.cc:165]              C:0x600003d043c0 grpc_combiner_execute c=0x600002617970 last=1

I0723 12:47:28.178056000 123145435414528 chttp2_transport.cc:827]      W:0x10180da00 SERVER state WRITING -> WRITING+MORE [INITIAL_WRITE]

I0723 12:47:28.178061000 123145435414528 ref_counted.h:98]             chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:3032 ref 4 -> 5 benign_reclaimer

I0723 12:47:28.178082000 123145435414528 combiner.cc:165]              C:0x600003d042d0 grpc_combiner_execute c=0x101305ff0 last=1

D0723 12:47:28.178119000 123145435414528 transport.cc:45]              SERVER_CHANNEL 0x101645fa0:0x101645f20   REF 1->2 connectivity

I0723 12:47:28.178144000 123145435414528 chttp2_transport.cc:1856]     perform_transport_op[t=0x10180da00]: ON_CONNECTIVITY_STATE_CHANGE:p=0x101646110:from=IDLE SET_ACCEPT_STREAM:0x100ae4130(0x101646080,...)

I0723 12:47:28.178332000 123145435414528 ref_counted.h:98]             chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:1860 ref 5 -> 6 transport_op

I0723 12:47:28.178340000 123145435414528 combiner.cc:165]              C:0x600003d043c0 grpc_combiner_execute c=0x10163ef48 last=3

I0723 12:47:28.178345000 123145435414528 ref_counted.h:98]             chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:3195 ref 6 -> 7 reading_action

I0723 12:47:28.178349000 123145435414528 combiner.cc:165]              C:0x600003d043c0 grpc_combiner_execute c=0x10180dbc0 last=5

I0723 12:47:28.178352000 123145435414528 ref_counted.h:98]             chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/server/chttp2_server.cc:166 ref 7 -> 8 receive settings timeout

I0723 12:47:28.178629000 123145435414528 timer_generic.cc:365]         TIMER 0x101311fb8: SET 798982 now 678982 call 0x101311ff0[0x100a0dd10]

I0723 12:47:28.178667000 123145435414528 timer_generic.cc:401]           .. add to shard 16 with queue_deadline_cap=679069 => is_first_timer=false

D0723 12:47:28.178672000 123145435414528 exec_ctx.cc:43]               closure 0x101320390 finished

I0723 12:47:28.178677000 123145435414528 combiner.cc:224]              C:0x600003d043c0 grpc_combiner_continue_exec_ctx contended=0 exec_ctx_ready_to_finish=0 time_to_execute_final_list=0

I0723 12:47:28.178680000 123145435414528 combiner.cc:254]              C:0x600003d043c0 maybe_finish_one n=0x600002617970

I0723 12:47:28.178683000 123145435414528 combiner.cc:339]              C:0x600003d043c0 grpc_combiner_execute_finally c=0x10180dad0; ac=0x600003d043c0

I0723 12:47:28.178703000 123145435414528 combiner.cc:296]              C:0x600003d043c0 finish old_state=9

I0723 12:47:28.178707000 123145435414528 combiner.cc:224]              C:0x600003d043c0 grpc_combiner_continue_exec_ctx contended=0 exec_ctx_ready_to_finish=0 time_to_execute_final_list=0

I0723 12:47:28.178816000 123145435414528 combiner.cc:254]              C:0x600003d043c0 maybe_finish_one n=0x10163ef48

I0723 12:47:28.178820000 123145435414528 connectivity_state.cc:116]    CONWATCH: 0x10180dd50 server_transport: from IDLE [cur=READY] notify=0x101646110

D0723 12:47:28.178824000 123145435414528 exec_ctx.cc:34]               running closure 0x10163ee80: created [/Pods/gRPC-Core/src/core/lib/transport/transport.cc:262]: run [/Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:1847]

D0723 12:47:28.178828000 123145435414528 exec_ctx.cc:43]               closure 0x10163ee80 finished

I0723 12:47:28.178834000 123145435414528 ref_counted.h:139]            chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:1849 unref 8 -> 7 transport_op

I0723 12:47:28.179115000 123145435414528 combiner.cc:296]              C:0x600003d043c0 finish old_state=7

D0723 12:47:28.179123000 123145435414528 exec_ctx.cc:34]               running closure 0x101646110: created [/Pods/gRPC-Core/src/core/lib/surface/server.cc:935]: scheduled [/Pods/gRPC-Core/src/core/lib/transport/connectivity_state.cc:143]

I0723 12:47:28.179129000 123145435414528 chttp2_transport.cc:1856]     perform_transport_op[t=0x10180da00]: ON_CONNECTIVITY_STATE_CHANGE:p=0x101646110:from=READY

I0723 12:47:28.179152000 123145435414528 ref_counted.h:98]             chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:1860 ref 7 -> 8 transport_op

I0723 12:47:28.179155000 123145435414528 combiner.cc:165]              C:0x600003d043c0 grpc_combiner_execute c=0x101320888 last=5

D0723 12:47:28.179292000 123145435414528 exec_ctx.cc:43]               closure 0x101646110 finished

I0723 12:47:28.179300000 123145435414528 combiner.cc:224]              C:0x600003d043c0 grpc_combiner_continue_exec_ctx contended=0 exec_ctx_ready_to_finish=0 time_to_execute_final_list=0

I0723 12:47:28.179321000 123145435414528 combiner.cc:254]              C:0x600003d043c0 maybe_finish_one n=0x10180dbc0

I0723 12:47:28.179326000 123145435414528 ref_counted.h:98]             chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:2560 ref 8 -> 9 keep_reading

I0723 12:47:28.179329000 123145435414528 timer_generic.cc:467]         TIMER 0x10180f570: CANCEL pending=true

I0723 12:47:28.179332000 123145435414528 combiner.cc:165]              C:0x600003d043c0 grpc_combiner_execute c=0x10180f430 last=7

D0723 12:47:28.179335000 123145435414528 tcp_posix.cc:556]             TCP   ref 0x101336940 : read 1 -> 2

I0723 12:47:28.179457000 123145435414528 tcp_posix.cc:251]             TCP:0x101336940 notify_on_read

I0723 12:47:28.179514000 123145435414528 ref_counted.h:139]            chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:2572 unref 9 -> 8 keep_reading

I0723 12:47:28.179524000 123145435414528 combiner.cc:296]              C:0x600003d043c0 finish old_state=9

I0723 12:47:28.179529000 123145435414528 combiner.cc:224]              C:0x600003d043c0 grpc_combiner_continue_exec_ctx contended=0 exec_ctx_ready_to_finish=0 time_to_execute_final_list=0

I0723 12:47:28.179532000 123145435414528 combiner.cc:254]              C:0x600003d043c0 maybe_finish_one n=0x101320888

I0723 12:47:28.179536000 123145435414528 connectivity_state.cc:116]    CONWATCH: 0x10180dd50 server_transport: from READY [cur=READY] notify=0x101646110

D0723 12:47:28.179559000 123145435414528 exec_ctx.cc:34]               running closure 0x1013207c0: created [/Pods/gRPC-Core/src/core/lib/transport/transport.cc:262]: run [/Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:1847]

D0723 12:47:28.179671000 123145435414528 exec_ctx.cc:43]               closure 0x1013207c0 finished

I0723 12:47:28.179703000 123145435414528 ref_counted.h:139]            chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:1849 unref 8 -> 7 transport_op

I0723 12:47:28.179726000 123145435414528 combiner.cc:296]              C:0x600003d043c0 finish old_state=7

I0723 12:47:28.179732000 123145435414528 combiner.cc:224]              C:0x600003d043c0 grpc_combiner_continue_exec_ctx contended=0 exec_ctx_ready_to_finish=0 time_to_execute_final_list=0

I0723 12:47:28.179736000 123145435414528 combiner.cc:254]              C:0x600003d043c0 maybe_finish_one n=0x10180f430

I0723 12:47:28.179859000 123145435414528 ref_counted.h:98]             chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:2718 ref 7 -> 8 init keepalive ping

I0723 12:47:28.179864000 123145435414528 timer_generic.cc:365]         TIMER 0x10180f570: SET 7878982 now 678982 call 0x10180f430[0x100a19fd0]

I0723 12:47:28.179885000 123145435414528 timer_generic.cc:401]           .. add to shard 14 with queue_deadline_cap=679069 => is_first_timer=false

I0723 12:47:28.179889000 123145435414528 ref_counted.h:139]            chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:2723 unref 8 -> 7 init keepalive ping

I0723 12:47:28.179892000 123145435414528 combiner.cc:296]              C:0x600003d043c0 finish old_state=5

I0723 12:47:28.179895000 123145435414528 combiner.cc:224]              C:0x600003d043c0 grpc_combiner_continue_exec_ctx contended=0 exec_ctx_ready_to_finish=0 time_to_execute_final_list=1

I0723 12:47:28.180040000 123145435414528 combiner.cc:278]              C:0x600003d043c0 execute_final[0] c=0x10180dad0

D0723 12:47:28.180049000 123145435414528 flow_control.cc:113]          0x10180f120[0][svr] | t updt sent | trw:                         65535, tlw:                       4194304, taw:              65535 -> 4194304, srw:                              , slw:                              , saw:

I0723 12:47:28.180054000 123145435414528 combiner.cc:165]              C:0x600003d043c0 grpc_combiner_execute c=0x10180f290 last=3

I0723 12:47:28.180057000 123145435414528 writing.cc:111]               SERVER: Ping sent [0x6000044943a0]: 2/2

I0723 12:47:28.180061000 123145435414528 chttp2_transport.cc:827]      W:0x10180da00 SERVER state WRITING+MORE -> WRITING [begin write in current thread]

I0723 12:47:28.180064000 123145435414528 combiner.cc:296]              C:0x600003d043c0 finish old_state=5

D0723 12:47:28.180214000 123145435414528 exec_ctx.cc:34]               running closure 0x10180db20: created [/Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:1038]: scheduled [/Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:1039]

I0723 12:47:28.180221000 123145435414528 tcp_posix.cc:984]             WRITE 0x101336940 (peer=ipv6:[::1]:64145)

D0723 12:47:28.180227000 123145435414528 tcp_posix.cc:988]             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 '............@.....@...... .......'

I0723 12:47:28.180230000 123145435414528 tcp_posix.cc:984]             WRITE 0x101336940 (peer=ipv6:[::1]:64145)

D0723 12:47:28.180234000 123145435414528 tcp_posix.cc:988]             DATA: 00 00 04 08 00 00 00 00 00 00 3f 00 01 00 00 08 06 00 00 00 00 00 00 '..........?............'

I0723 12:47:28.180331000 123145435414528 tcp_posix.cc:984]             WRITE 0x101336940 (peer=ipv6:[::1]:64145)

D0723 12:47:28.180356000 123145435414528 tcp_posix.cc:988]             DATA: 00 00 00 00 00 00 00 '.......'

I0723 12:47:28.180405000 123145435414528 tcp_posix.cc:1022]            write: "No Error"

I0723 12:47:28.180413000 123145435414528 combiner.cc:165]              C:0x600003d043c0 grpc_combiner_execute c=0x10180db70 last=3

D0723 12:47:28.180418000 123145435414528 exec_ctx.cc:43]               closure 0x10180db20 finished

I0723 12:47:28.180424000 123145435414528 combiner.cc:224]              C:0x600003d043c0 grpc_combiner_continue_exec_ctx contended=0 exec_ctx_ready_to_finish=0 time_to_execute_final_list=0

I0723 12:47:28.180428000 123145435414528 combiner.cc:254]              C:0x600003d043c0 maybe_finish_one n=0x10180f290

I0723 12:47:28.180433000 123145435414528 chttp2_transport.cc:2590]     ipv6:[::1]:64145: Start BDP ping err="No Error"

I0723 12:47:28.180496000 123145435414528 timer_generic.cc:467]         TIMER 0x10180f570: CANCEL pending=true

I0723 12:47:28.180506000 123145435414528 combiner.cc:165]              C:0x600003d043c0 grpc_combiner_execute c=0x10180f430 last=5

I0723 12:47:28.180512000 123145435414528 bdp_estimator.h:66]           bdp[ipv6:[::1]:64145]:start acc=0 est=65536

I0723 12:47:28.180517000 123145435414528 combiner.cc:296]              C:0x600003d043c0 finish old_state=7

I0723 12:47:28.180523000 123145435414528 combiner.cc:224]              C:0x600003d043c0 grpc_combiner_continue_exec_ctx contended=0 exec_ctx_ready_to_finish=0 time_to_execute_final_list=0

I0723 12:47:28.180527000 123145435414528 combiner.cc:254]              C:0x600003d043c0 maybe_finish_one n=0x10180db70

I0723 12:47:28.180532000 123145435414528 chttp2_transport.cc:827]      W:0x10180da00 SERVER state WRITING -> IDLE [finish writing]

I0723 12:47:28.180537000 123145435414528 ref_counted.h:139]            chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:1099 unref 7 -> 6 writing

I0723 12:47:28.180728000 123145435414528 combiner.cc:296]              C:0x600003d043c0 finish old_state=5

I0723 12:47:28.180757000 123145435414528 combiner.cc:224]              C:0x600003d043c0 grpc_combiner_continue_exec_ctx contended=0 exec_ctx_ready_to_finish=0 time_to_execute_final_list=0

I0723 12:47:28.180760000 123145435414528 combiner.cc:254]              C:0x600003d043c0 maybe_finish_one n=0x10180f430

I0723 12:47:28.180764000 123145435414528 ref_counted.h:98]             chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:2718 ref 6 -> 7 init keepalive ping

I0723 12:47:28.180768000 123145435414528 timer_generic.cc:365]         TIMER 0x10180f570: SET 7878982 now 678982 call 0x10180f430[0x100a19fd0]

I0723 12:47:28.180772000 123145435414528 timer_generic.cc:401]           .. add to shard 14 with queue_deadline_cap=679069 => is_first_timer=false

I0723 12:47:28.180899000 123145435414528 ref_counted.h:139]            chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:2723 unref 7 -> 6 init keepalive ping

I0723 12:47:28.180902000 123145435414528 combiner.cc:296]              C:0x600003d043c0 finish old_state=3

I0723 12:47:28.180905000 123145435414528 combiner.cc:224]              C:0x600003d042d0 grpc_combiner_continue_exec_ctx contended=0 exec_ctx_ready_to_finish=0 time_to_execute_final_list=0

I0723 12:47:28.180908000 123145435414528 combiner.cc:254]              C:0x600003d042d0 maybe_finish_one n=0x101305ff0

I0723 12:47:28.180911000 123145435414528 combiner.cc:296]              C:0x600003d042d0 finish old_state=3

I0723 12:47:28.180934000 123145435414528 ev_posix.cc:323]              (polling-api) pollset_work(0x101705fd8, 1274083) end

I0723 12:47:28.180938000 123145435414528 ev_posix.cc:320]              (polling-api) pollset_work(0x101705fd8, 1274083) begin

D0723 12:47:28.181080000 123145435414528 ev_poll_posix.cc:371]         FD 5 0x600003b18000   ref 2 3 -> 5 [multipoller_start; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1043]

D0723 12:47:28.181084000 123145435414528 ev_poll_posix.cc:371]         FD 6 0x600003b100e0   ref 2 3 -> 5 [multipoller_start; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1043]

D0723 12:47:28.181088000 123145435414528 ev_poll_posix.cc:371]         FD 9 0x600003b04380   ref 2 3 -> 5 [multipoller_start; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1043]

D0723 12:47:28.181092000 123145435414528 ev_poll_posix.cc:371]         FD 5 0x600003b18000   ref 2 5 -> 7 [poll; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:647]

D0723 12:47:28.181095000 123145435414528 ev_poll_posix.cc:388]         FD 5 0x600003b18000 unref 2 7 -> 5 [multipoller_start; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1056]

D0723 12:47:28.181206000 123145435414528 ev_poll_posix.cc:371]         FD 6 0x600003b100e0   ref 2 5 -> 7 [poll; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:647]

D0723 12:47:28.181213000 123145435414528 ev_poll_posix.cc:388]         FD 6 0x600003b100e0 unref 2 7 -> 5 [multipoller_start; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1056]

D0723 12:47:28.181217000 123145435414528 ev_poll_posix.cc:371]         FD 9 0x600003b04380   ref 2 5 -> 7 [poll; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:647]

D0723 12:47:28.181220000 123145435414528 ev_poll_posix.cc:388]         FD 9 0x600003b04380 unref 2 7 -> 5 [multipoller_start; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1056]

I0723 12:47:28.181327000 123145435414528 ev_poll_posix.cc:1067]        0x101705fd8 poll=1

I0723 12:47:28.181331000 123145435414528 ev_poll_posix.cc:1101]        0x101705fd8 got_event: 5 r:0 w:0 [0]

D0723 12:47:28.181335000 123145435414528 ev_poll_posix.cc:388]         FD 5 0x600003b18000 unref 2 5 -> 3 [poll; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:740]

I0723 12:47:28.181338000 123145435414528 ev_poll_posix.cc:1101]        0x101705fd8 got_event: 6 r:0 w:0 [0]

D0723 12:47:28.181341000 123145435414528 ev_poll_posix.cc:388]         FD 6 0x600003b100e0 unref 2 5 -> 3 [poll; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:740]

I0723 12:47:28.181344000 123145435414528 ev_poll_posix.cc:1101]        0x101705fd8 got_event: 9 r:1 w:1 [5]

D0723 12:47:28.181347000 123145435414528 ev_poll_posix.cc:388]         FD 9 0x600003b04380 unref 2 5 -> 3 [poll; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:740]

D0723 12:47:28.181426000 123145435414528 exec_ctx.cc:34]               running closure 0x101336ae0: created [/Pods/gRPC-Core/src/core/lib/iomgr/tcp_posix.cc:254]: scheduled [/Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:573]

I0723 12:47:28.181431000 123145435414528 tcp_posix.cc:535]             TCP:0x101336940 got_read: "No Error"

I0723 12:47:28.181433000 123145435414528 tcp_posix.cc:520]             TCP:0x101336940 alloc_slices

I0723 12:47:28.181438000 123145435414528 resource_quota.cc:886]        RQ anonymous_pool_10132ac00 ipv6:[::1]:64145: alloc 8192; free_pool -> -8192

I0723 12:47:28.181441000 123145435414528 combiner.cc:165]              C:0x600003d042d0 grpc_combiner_execute c=0x101305ea8 last=1

D0723 12:47:28.181444000 123145435414528 exec_ctx.cc:43]               closure 0x101336ae0 finished

I0723 12:47:28.181555000 123145435414528 combiner.cc:224]              C:0x600003d042d0 grpc_combiner_continue_exec_ctx contended=0 exec_ctx_ready_to_finish=0 time_to_execute_final_list=0

I0723 12:47:28.181558000 123145435414528 combiner.cc:254]              C:0x600003d042d0 maybe_finish_one n=0x101305ea8

I0723 12:47:28.181561000 123145435414528 combiner.cc:339]              C:0x600003d042d0 grpc_combiner_execute_finally c=0x10132ac88; ac=0x600003d042d0

I0723 12:47:28.181564000 123145435414528 combiner.cc:296]              C:0x600003d042d0 finish old_state=5

I0723 12:47:28.181567000 123145435414528 combiner.cc:224]              C:0x600003d042d0 grpc_combiner_continue_exec_ctx contended=0 exec_ctx_ready_to_finish=0 time_to_execute_final_list=1

I0723 12:47:28.181570000 123145435414528 combiner.cc:278]              C:0x600003d042d0 execute_final[0] c=0x10132ac88

I0723 12:47:28.181573000 123145435414528 resource_quota.cc:320]        RQ: check allocation for user 0x101305ea0 shutdown=0 free_pool=-8192

I0723 12:47:28.181663000 123145435414528 resource_quota.cc:346]        RQ anonymous_pool_10132ac00 ipv6:[::1]:64145: grant alloc 8192 bytes; rq_free_pool -> 9223372036854767615

I0723 12:47:28.181670000 123145435414528 combiner.cc:296]              C:0x600003d042d0 finish old_state=3

D0723 12:47:28.181674000 123145435414528 exec_ctx.cc:34]               running closure 0x101336be0: created [/Pods/gRPC-Core/src/core/lib/iomgr/resource_quota.cc:983]: scheduled [/Pods/gRPC-Core/src/core/lib/iomgr/resource_quota.cc:360]

D0723 12:47:28.181679000 123145435414528 exec_ctx.cc:34]               running closure 0x101336c30: created [/Pods/gRPC-Core/src/core/lib/iomgr/resource_quota.cc:985]: run [/Pods/gRPC-Core/src/core/lib/iomgr/resource_quota.cc:593]

I0723 12:47:28.181683000 123145435414528 tcp_posix.cc:502]             TCP:0x101336940 read_allocation_done: "No Error"

I0723 12:47:28.181800000 123145435414528 tcp_posix.cc:409]             TCP:0x101336940 call_cb 0x10180dbc0 0x100a190f0:0x10180da00

I0723 12:47:28.181804000 123145435414528 tcp_posix.cc:412]             READ 0x101336940 (peer=ipv6:[::1]:64145) error="No Error"

D0723 12:47:28.181810000 123145435414528 tcp_posix.cc:418]             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 00 04 00 00 00 00 00 00 00 00 04 01 00 00 00 00 00 00 08 06 01 00 00 00 00 00 00 00 00 00 00 00 00 'PRI * HTTP/2.0....SM.......................................'

I0723 12:47:28.181813000 123145435414528 combiner.cc:165]              C:0x600003d043c0 grpc_combiner_execute c=0x10180dbc0 last=1

D0723 12:47:28.181816000 123145435414528 tcp_posix.cc:495]             TCP unref 0x101336940 : read 2 -> 1

D0723 12:47:28.181819000 123145435414528 exec_ctx.cc:43]               closure 0x101336c30 finished

D0723 12:47:28.181821000 123145435414528 exec_ctx.cc:43]               closure 0x101336be0 finished

I0723 12:47:28.181894000 123145435414528 combiner.cc:224]              C:0x600003d043c0 grpc_combiner_continue_exec_ctx contended=0 exec_ctx_ready_to_finish=0 time_to_execute_final_list=0

I0723 12:47:28.181898000 123145435414528 combiner.cc:254]              C:0x600003d043c0 maybe_finish_one n=0x10180dbc0

I0723 12:47:28.181903000 123145435414528 combiner.cc:165]              C:0x600003d043c0 grpc_combiner_execute c=0x10180f2e0 last=3

I0723 12:47:28.181908000 123145435414528 ref_counted.h:98]             chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:2560 ref 6 -> 7 keep_reading

I0723 12:47:28.181911000 123145435414528 timer_generic.cc:467]         TIMER 0x10180f570: CANCEL pending=true

I0723 12:47:28.181914000 123145435414528 combiner.cc:165]              C:0x600003d043c0 grpc_combiner_execute c=0x10180f430 last=5

D0723 12:47:28.181917000 123145435414528 tcp_posix.cc:556]             TCP   ref 0x101336940 : read 1 -> 2

I0723 12:47:28.182014000 123145435414528 ref_counted.h:139]            chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:2572 unref 7 -> 6 keep_reading

I0723 12:47:28.182037000 123145435414528 combiner.cc:296]              C:0x600003d043c0 finish old_state=7

D0723 12:47:28.182043000 123145435414528 exec_ctx.cc:34]               running closure 0x101312040: created [/Pods/gRPC-Core/src/core/ext/transport/chttp2/server/chttp2_server.cc:160]: scheduled [/Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/frame_settings.cc:137]

I0723 12:47:28.182046000 123145435414528 timer_generic.cc:467]         TIMER 0x101311fb8: CANCEL pending=true

D0723 12:47:28.182049000 123145435414528 exec_ctx.cc:43]               closure 0x101312040 finished

D0723 12:47:28.182053000 123145435414528 exec_ctx.cc:34]               running closure 0x101336ae0: created [/Pods/gRPC-Core/src/core/lib/iomgr/tcp_posix.cc:254]: scheduled [/Pods/gRPC-Core/src/core/lib/iomgr/tcp_posix.cc:568]

I0723 12:47:28.182123000 123145435414528 tcp_posix.cc:535]             TCP:0x101336940 got_read: "No Error"

I0723 12:47:28.182128000 123145435414528 tcp_posix.cc:526]             TCP:0x101336940 do_read

I0723 12:47:28.182133000 123145435414528 tcp_posix.cc:251]             TCP:0x101336940 notify_on_read

D0723 12:47:28.182136000 123145435414528 exec_ctx.cc:43]               closure 0x101336ae0 finished

D0723 12:47:28.182140000 123145435414528 exec_ctx.cc:34]               running closure 0x101311ff0: created [/Pods/gRPC-Core/src/core/ext/transport/chttp2/server/chttp2_server.cc:168]: scheduled [/Pods/gRPC-Core/src/core/lib/iomgr/timer_generic.cc:474]

I0723 12:47:28.182231000 123145435414528 ref_counted.h:139]            chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/server/chttp2_server.cc:82 unref 6 -> 5 receive settings timeout

I0723 12:47:28.182237000 123145435414528 ev_posix.cc:369]              (polling-api) pollset_set_del_pollset(0x600003000b40, 0x101705fd8)

I0723 12:47:28.182240000 123145435414528 ev_posix.cc:355]              (polling-api) pollset_set_destroy(0x600003000b40)

D0723 12:47:28.182243000 123145435414528 exec_ctx.cc:43]               closure 0x101311ff0 finished

I0723 12:47:28.182247000 123145435414528 combiner.cc:224]              C:0x600003d043c0 grpc_combiner_continue_exec_ctx contended=0 exec_ctx_ready_to_finish=0 time_to_execute_final_list=0

I0723 12:47:28.182249000 123145435414528 combiner.cc:254]              C:0x600003d043c0 maybe_finish_one n=0x10180f2e0

I0723 12:47:28.182252000 123145435414528 chttp2_transport.cc:2603]     ipv6:[::1]:64145: Complete BDP ping err="No Error"

I0723 12:47:28.182342000 123145435414528 bdp_estimator.cc:50]          bdp[ipv6:[::1]:64145]:complete acc=59 est=65536 dt=0.001820 bw=0.259356Mbs bw_est=0.000000Mbs

I0723 12:47:28.182349000 123145435414528 timer_generic.cc:365]         TIMER 0x10180f3f8: SET 679090 now 678990 call 0x10180f240[0x100a19f10]

I0723 12:47:28.182352000 123145435414528 timer_generic.cc:401]           .. add to shard 13 with queue_deadline_cap=679069 => is_first_timer=false

I0723 12:47:28.182355000 123145435414528 combiner.cc:296]              C:0x600003d043c0 finish old_state=5

I0723 12:47:28.182359000 123145435414528 combiner.cc:224]              C:0x600003d043c0 grpc_combiner_continue_exec_ctx contended=0 exec_ctx_ready_to_finish=0 time_to_execute_final_list=0

I0723 12:47:28.182361000 123145435414528 combiner.cc:254]              C:0x600003d043c0 maybe_finish_one n=0x10180f430

I0723 12:47:28.182364000 123145435414528 ref_counted.h:98]             chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:2718 ref 5 -> 6 init keepalive ping

I0723 12:47:28.182459000 123145435414528 timer_generic.cc:365]         TIMER 0x10180f570: SET 7878990 now 678990 call 0x10180f430[0x100a19fd0]

I0723 12:47:28.182465000 123145435414528 timer_generic.cc:401]           .. add to shard 14 with queue_deadline_cap=679069 => is_first_timer=false

I0723 12:47:28.182468000 123145435414528 ref_counted.h:139]            chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:2723 unref 6 -> 5 init keepalive ping

I0723 12:47:28.182471000 123145435414528 combiner.cc:296]              C:0x600003d043c0 finish old_state=3

I0723 12:47:28.182474000 123145435414528 ev_posix.cc:323]              (polling-api) pollset_work(0x101705fd8, 1274083) end

I0723 12:47:28.182477000 123145435414528 ev_posix.cc:320]              (polling-api) pollset_work(0x101705fd8, 1274083) begin

D0723 12:47:28.182540000 123145435414528 ev_poll_posix.cc:371]         FD 5 0x600003b18000   ref 2 3 -> 5 [multipoller_start; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1043]

D0723 12:47:28.182543000 123145435414528 ev_poll_posix.cc:371]         FD 6 0x600003b100e0   ref 2 3 -> 5 [multipoller_start; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1043]

D0723 12:47:28.182546000 123145435414528 ev_poll_posix.cc:371]         FD 9 0x600003b04380   ref 2 3 -> 5 [multipoller_start; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1043]

D0723 12:47:28.182550000 123145435414528 ev_poll_posix.cc:371]         FD 5 0x600003b18000   ref 2 5 -> 7 [poll; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:647]

D0723 12:47:28.182553000 123145435414528 ev_poll_posix.cc:388]         FD 5 0x600003b18000 unref 2 7 -> 5 [multipoller_start; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1056]

D0723 12:47:28.182639000 123145435414528 ev_poll_posix.cc:371]         FD 6 0x600003b100e0   ref 2 5 -> 7 [poll; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:647]

D0723 12:47:28.182643000 123145435414528 ev_poll_posix.cc:388]         FD 6 0x600003b100e0 unref 2 7 -> 5 [multipoller_start; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1056]

D0723 12:47:28.182646000 123145435414528 ev_poll_posix.cc:371]         FD 9 0x600003b04380   ref 2 5 -> 7 [poll; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:647]

D0723 12:47:28.182649000 123145435414528 ev_poll_posix.cc:388]         FD 9 0x600003b04380 unref 2 7 -> 5 [multipoller_start; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:1056]

I0723 12:47:28.182741000 123145435414528 ev_poll_posix.cc:1067]        0x101705fd8 poll=1

I0723 12:47:28.182744000 123145435414528 ev_poll_posix.cc:1101]        0x101705fd8 got_event: 5 r:0 w:0 [0]

D0723 12:47:28.182747000 123145435414528 ev_poll_posix.cc:388]         FD 5 0x600003b18000 unref 2 5 -> 3 [poll; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:740]

I0723 12:47:28.182750000 123145435414528 ev_poll_posix.cc:1101]        0x101705fd8 got_event: 6 r:0 w:0 [0]

D0723 12:47:28.182753000 123145435414528 ev_poll_posix.cc:388]         FD 6 0x600003b100e0 unref 2 5 -> 3 [poll; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:740]

I0723 12:47:28.182756000 123145435414528 ev_poll_posix.cc:1101]        0x101705fd8 got_event: 9 r:1 w:0 [1]

D0723 12:47:28.182759000 123145435414528 ev_poll_posix.cc:388]         FD 9 0x600003b04380 unref 2 5 -> 3 [poll; /Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:740]

D0723 12:47:28.182830000 123145435414528 exec_ctx.cc:34]               running closure 0x101336ae0: created [/Pods/gRPC-Core/src/core/lib/iomgr/tcp_posix.cc:254]: scheduled [/Pods/gRPC-Core/src/core/lib/iomgr/ev_poll_posix.cc:573]

I0723 12:47:28.182834000 123145435414528 tcp_posix.cc:535]             TCP:0x101336940 got_read: "No Error"

I0723 12:47:28.182836000 123145435414528 tcp_posix.cc:526]             TCP:0x101336940 do_read

I0723 12:47:28.182842000 123145435414528 tcp_posix.cc:409]             TCP:0x101336940 call_cb 0x10180dbc0 0x100a190f0:0x10180da00

I0723 12:47:28.182845000 123145435414528 tcp_posix.cc:412]             READ 0x101336940 (peer=ipv6:[::1]:64145) error="No Error"

I0723 12:47:28.182930000 123145435414528 combiner.cc:165]              C:0x600003d043c0 grpc_combiner_execute c=0x10180dbc0 last=1

D0723 12:47:28.182934000 123145435414528 tcp_posix.cc:495]             TCP unref 0x101336940 : read 2 -> 1

D0723 12:47:28.182936000 123145435414528 exec_ctx.cc:43]               closure 0x101336ae0 finished

I0723 12:47:28.182940000 123145435414528 combiner.cc:224]              C:0x600003d043c0 grpc_combiner_continue_exec_ctx contended=0 exec_ctx_ready_to_finish=0 time_to_execute_final_list=0

I0723 12:47:28.183057000 123145435414528 combiner.cc:254]              C:0x600003d043c0 maybe_finish_one n=0x10180dbc0

D0723 12:47:28.183065000 123145435414528 transport.cc:45]              SERVER_CHANNEL 0x101645fa0:0x101645f20   REF 2->3 call

D0723 12:47:28.183075000 123145435414528 transport.cc:45]              CALL_STACK 0x1030a5a70:0x1030a5070   REF 1->2 chttp2

I0723 12:47:28.183078000 123145435414528 ref_counted.h:98]             chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:657 ref 5 -> 6 stream

I0723 12:47:28.183082000 123145435414528 ref_counted.h:98]             chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:3041 ref 6 -> 7 destructive_reclaimer

I0723 12:47:28.183086000 123145435414528 combiner.cc:165]              C:0x600003d042d0 grpc_combiner_execute c=0x101306040 last=1

I0723 12:47:28.183169000 123145435414528 call.cc:1511]                 ops[0]: RECV_INITIAL_METADATA ptr=0x1030a5bf8

D0723 12:47:28.183173000 123145435414528 transport.cc:45]              CALL_STACK 0x1030a5a70:0x1030a5070   REF 2->3 completion

I0723 12:47:28.183177000 123145435414528 call_combiner.cc:116]         ==> grpc_call_combiner_start() [0x1030a5080] closure=0x1030a76a0 [/Pods/gRPC-Core/src/core/lib/surface/call.cc:628: executing batch] error="No Error"

I0723 12:47:28.183180000 123145435414528 call_combiner.cc:125]           size: 0 -> 1

I0723 12:47:28.183182000 123145435414528 call_combiner.cc:134]           EXECUTING IMMEDIATELY

I0723 12:47:28.183185000 123145435414528 parsing.cc:656]               parsing initial_metadata

I0723 12:47:28.183191000 123145435414528 hpack_parser.cc:636]          Decode: ':method: POST', elem_interned=1 [3], k_interned=1, v_interned=1

I0723 12:47:28.183195000 123145435414528 parsing.cc:407]               HTTP:1:HDR:SVR: :method: 50 4f 53 54 'POST'

I0723 12:47:28.183276000 123145435414528 hpack_parser.cc:636]          Decode: ':scheme: http', elem_interned=1 [3], k_interned=1, v_interned=1

I0723 12:47:28.183279000 123145435414528 parsing.cc:407]               HTTP:1:HDR:SVR: :scheme: 68 74 74 70 'http'

D0723 12:47:28.183292000 123145435414528 metadata.cc:291]              ELM   REF:0x6000033101e0:0->1: ':path' = '/protoService/Method'

I0723 12:47:28.183296000 123145435414528 hpack_parser.cc:636]          Decode: ':path: /protoService/Method', elem_interned=1 [1], k_interned=1, v_interned=1

D0723 12:47:28.183300000 123145435414528 hpack_table.cc:335]           ELM   REF:0x6000033101e0:1->2: ':path' = '/protoService/Method'

D0723 12:47:28.183379000 123145435414528 metadata.cc:291]              ELM   REF:0x60000331c000:0->1: ':authority' = 'localhost:8081'

I0723 12:47:28.183383000 123145435414528 hpack_parser.cc:636]          Decode: ':authority: localhost:8081', elem_interned=1 [1], k_interned=1, v_interned=1

D0723 12:47:28.183386000 123145435414528 hpack_table.cc:335]           ELM   REF:0x60000331c000:1->2: ':authority' = 'localhost:8081'

I0723 12:47:28.183390000 123145435414528 parsing.cc:407]               HTTP:1:HDR:SVR: :authority: 6c 6f 63 61 6c 68 6f 73 74 3a 38 30 38 31 'localhost:8081'

I0723 12:47:28.183394000 123145435414528 hpack_parser.cc:636]          Decode: 'content-type: application/grpc', elem_interned=1 [3], k_interned=1, v_interned=1

I0723 12:47:28.183398000 123145435414528 parsing.cc:407]               HTTP:1:HDR:SVR: content-type: 61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc'

D0723 12:47:28.183481000 123145435414528 metadata.cc:291]              ELM   REF:0x6000033001e0:0->1: 'user-agent' = 'grpc-go/1.21.0'

I0723 12:47:28.183485000 123145435414528 hpack_parser.cc:636]          Decode: 'user-agent: grpc-go/1.21.0', elem_interned=1 [1], k_interned=1, v_interned=1

D0723 12:47:28.183487000 123145435414528 hpack_table.cc:335]           ELM   REF:0x6000033001e0:1->2: 'user-agent' = 'grpc-go/1.21.0'

I0723 12:47:28.183491000 123145435414528 parsing.cc:407]               HTTP:1:HDR:SVR: user-agent: 67 72 70 63 2d 67 6f 2f 31 2e 32 31 2e 30 'grpc-go/1.21.0'

I0723 12:47:28.183496000 123145435414528 hpack_parser.cc:636]          Decode: 'te: trailers', elem_interned=1 [3], k_interned=1, v_interned=1

I0723 12:47:28.183499000 123145435414528 parsing.cc:407]               HTTP:1:HDR:SVR: te: 74 72 61 69 6c 65 72 73 'trailers'

D0723 12:47:28.183507000 123145435414528 flow_control.cc:113]          0x10180f120[1][svr] |   data recv | trw:                         65535, tlw:                       4194304, taw:            4194304 -> 4194279, srw:                         65535, slw:            4194304 -> 4194279, saw:            4194304 -> 4194279

I0723 12:47:28.183580000 123145435414528 ref_counted.h:98]             chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:2560 ref 7 -> 8 keep_reading

I0723 12:47:28.183584000 123145435414528 timer_generic.cc:467]         TIMER 0x10180f570: CANCEL pending=true

I0723 12:47:28.183587000 123145435414528 combiner.cc:165]              C:0x600003d043c0 grpc_combiner_execute c=0x10180f430 last=3

D0723 12:47:28.183590000 123145435414528 tcp_posix.cc:556]             TCP   ref 0x101336940 : read 1 -> 2

I0723 12:47:28.183593000 123145435414528 ref_counted.h:139]            chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:2572 unref 8 -> 7 keep_reading

I0723 12:47:28.183687000 123145435414528 combiner.cc:296]              C:0x600003d043c0 finish old_state=5

D0723 12:47:28.183695000 123145435414528 exec_ctx.cc:34]               running closure 0x1030a76a0: created [/Pods/gRPC-Core/src/core/lib/surface/call.cc:626]: scheduled [/Pods/gRPC-Core/src/core/lib/iomgr/call_combiner.cc:81]

I0723 12:47:28.183700000 123145435414528 call.cc:615]                  OP[server:0x1030a5af0]:  RECV_INITIAL_METADATA

I0723 12:47:28.183704000 123145435414528 channel_stack.cc:226]         OP[message_size:0x1030a5b08]:  RECV_INITIAL_METADATA

I0723 12:47:28.183708000 123145435414528 channel_stack.cc:226]         OP[deadline:0x1030a5b20]:  RECV_INITIAL_METADATA

I0723 12:47:28.183711000 123145435414528 channel_stack.cc:226]         OP[http-server:0x1030a5b38]:  RECV_INITIAL_METADATA

I0723 12:47:28.183714000 123145435414528 channel_stack.cc:226]         OP[message_compress:0x1030a5b50]:  RECV_INITIAL_METADATA

I0723 12:47:28.183775000 123145435414528 channel_stack.cc:226]         OP[connected:0x1030a5b68]:  RECV_INITIAL_METADATA

I0723 12:47:28.183781000 123145435414528 chttp2_transport.cc:1689]     perform_stream_op[s=0x1030a6ad0]:  RECV_INITIAL_METADATA

D0723 12:47:28.183784000 123145435414528 transport.cc:45]              CALL_STACK 0x1030a5a70:0x1030a5070   REF 3->4 perform_stream_op

I0723 12:47:28.183787000 123145435414528 combiner.cc:165]              C:0x600003d043c0 grpc_combiner_execute c=0x1030a7628 last=3

I0723 12:47:28.183790000 123145435414528 call_combiner.cc:153]         ==> grpc_call_combiner_stop() [0x1030a5080] [/Pods/gRPC-Core/src/core/lib/channel/connected_channel.cc:137: passed batch to transport]

I0723 12:47:28.183793000 123145435414528 call_combiner.cc:160]           size: 1 -> 0

I0723 12:47:28.183795000 123145435414528 call_combiner.cc:189]           queue empty

D0723 12:47:28.183873000 123145435414528 exec_ctx.cc:43]               closure 0x1030a76a0 finished

D0723 12:47:28.183877000 123145435414528 exec_ctx.cc:34]               running closure 0x101336ae0: created [/Pods/gRPC-Core/src/core/lib/iomgr/tcp_posix.cc:254]: scheduled [/Pods/gRPC-Core/src/core/lib/iomgr/tcp_posix.cc:568]

I0723 12:47:28.183880000 123145435414528 tcp_posix.cc:535]             TCP:0x101336940 got_read: "No Error"

I0723 12:47:28.183882000 123145435414528 tcp_posix.cc:526]             TCP:0x101336940 do_read

I0723 12:47:28.183886000 123145435414528 tcp_posix.cc:251]             TCP:0x101336940 notify_on_read

D0723 12:47:28.183889000 123145435414528 exec_ctx.cc:43]               closure 0x101336ae0 finished

I0723 12:47:28.183893000 123145435414528 combiner.cc:224]              C:0x600003d043c0 grpc_combiner_continue_exec_ctx contended=0 exec_ctx_ready_to_finish=0 time_to_execute_final_list=0

I0723 12:47:28.183971000 123145435414528 combiner.cc:254]              C:0x600003d043c0 maybe_finish_one n=0x10180f430

I0723 12:47:28.183974000 123145435414528 ref_counted.h:98]             chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:2718 ref 7 -> 8 init keepalive ping

I0723 12:47:28.183978000 123145435414528 timer_generic.cc:365]         TIMER 0x10180f570: SET 7878992 now 678992 call 0x10180f430[0x100a19fd0]

I0723 12:47:28.183981000 123145435414528 timer_generic.cc:401]           .. add to shard 14 with queue_deadline_cap=679069 => is_first_timer=false

I0723 12:47:28.183984000 123145435414528 ref_counted.h:139]            chttp2_refcount:0x10180da08 /Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:2723 unref 8 -> 7 init keepalive ping

I0723 12:47:28.183987000 123145435414528 combiner.cc:296]              C:0x600003d043c0 finish old_state=5

I0723 12:47:28.184066000 123145435414528 combiner.cc:224]              C:0x600003d043c0 grpc_combiner_continue_exec_ctx contended=0 exec_ctx_ready_to_finish=0 time_to_execute_final_list=0

I0723 12:47:28.184068000 123145435414528 combiner.cc:254]              C:0x600003d043c0 maybe_finish_one n=0x1030a7628

I0723 12:47:28.184072000 123145435414528 chttp2_transport.cc:1385]     perform_stream_op_locked:  RECV_INITIAL_METADATA; on_complete = 0x0

D0723 12:47:28.184076000 123145435414528 exec_ctx.cc:34]               running closure 0x1030a6998: created [/Pods/gRPC-Core/src/core/lib/channel/connected_channel.cc:77]: run [/Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:1217]

I0723 12:47:28.184080000 123145435414528 call_combiner.cc:116]         ==> grpc_call_combiner_start() [0x1030a5080] closure=0x1030a61c8 [/Pods/gRPC-Core/src/core/lib/channel/connected_channel.cc:60: recv_initial_metadata_ready] error="No Error"

I0723 12:47:28.184168000 123145435414528 call_combiner.cc:125]           size: 0 -> 1

I0723 12:47:28.184183000 123145435414528 call_combiner.cc:134]           EXECUTING IMMEDIATELY

D0723 12:47:28.184187000 123145435414528 exec_ctx.cc:43]               closure 0x1030a6998 finished

I0723 12:47:28.184191000 123145435414528 chttp2_transport.cc:1234]     complete_closure_step: t=0x10180da00 0x1030a7628 refs=0 flags=0x0000 desc=op->on_complete err="No Error" write_state=IDLE

D0723 12:47:28.184196000 123145435414528 exec_ctx.cc:34]               running closure 0x1030a7628: created [/Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:1406]: run [/Pods/gRPC-Core/src/core/ext/transport/chttp2/transport/chttp2_transport.cc:1258]

D0723 12:47:28.184199000 123145435414528 exec_ctx.cc:43]               closure 0x1030a7628 finished

D0723 12:47:28.184292000 123145435414528 transport.cc:59]              CALL_STACK 0x1030a5a70:0x1030a5070 UNREF 4->3 perform_stream_op

I0723 12:47:28.184298000 123145435414528 combiner.cc:296]              C:0x600003d043c0 finish old_state=3

D0723 12:47:28.184303000 123145435414528 exec_ctx.cc:34]               running closure 0x1030a61c8: created [/Pods/gRPC-Core/src/core/ext/filters/http/server/http_server_filter.cc:49]: scheduled [/Pods/gRPC-Core/src/core/lib/iomgr/call_combiner.cc:81]

D0723 12:47:28.184310000 123145435414528 exec_ctx.cc:34]               running closure 0x1030a5fc8: created [/Pods/gRPC-Core/src/core/ext/filters/deadline/deadline_filter.cc:315]: run [/Pods/gRPC-Core/src/core/ext/filters/http/server/http_server_filter.cc:337]

D0723 12:47:28.184314000 123145435414528 exec_ctx.cc:34]               running closure 0x1030a5c70: created [/Pods/gRPC-Core/src/core/lib/surface/server.cc:142]: run [/Pods/gRPC-Core/src/core/ext/filters/deadline/deadline_filter.cc:295]

D0723 12:47:28.184402000 123145435414528 metadata_batch.cc:225]        ELM UNREF:0x6000033101e0:2->1: ':path' = '/protoService/Method'

D0723 12:47:28.184405000 123145435414528 metadata_batch.cc:225]        ELM UNREF:0x60000331c000:2->1: ':authority' = 'localhost:8081'

D0723 12:47:28.184409000 123145435414528 exec_ctx.cc:34]               running closure 0x1030a5940: created [/Pods/gRPC-Core/src/core/lib/surface/call.cc:1751]: run [/Pods/gRPC-Core/src/core/lib/surface/server.cc:782]

I0723 12:47:28.184412000 123145435414528 call_combiner.cc:153]         ==> grpc_call_combiner_stop() [0x1030a5080] [/Pods/gRPC-Core/src/core/lib/surface/call.cc:1414: recv_initial_metadata_ready]

I0723 12:47:28.184498000 123145435414528 call_combiner.cc:160]           size: 1 -> 0

I0723 12:47:28.184502000 123145435414528 call_combiner.cc:189]           queue empty

D0723 12:47:28.184506000 123145435414528 transport.cc:59]              CALL_STACK 0x1030a5a70:0x1030a5070 UNREF 3->2 completion

D0723 12:47:28.184508000 123145435414528 exec_ctx.cc:43]               closure 0x1030a5940 finished

D0723 12:47:28.184511000 123145435414528 exec_ctx.cc:43]               closure 0x1030a5c70 finished

D0723 12:47:28.184513000 123145435414528 exec_ctx.cc:43]               closure 0x1030a5fc8 finished

D0723 12:47:28.184515000 123145435414528 exec_ctx.cc:43]               closure 0x1030a61c8 finished

D0723 12:47:28.184518000 123145435414528 exec_ctx.cc:34]               running closure 0x1030a5c20: created [/Pods/gRPC-Core/src/core/lib/surface/server.cc:884]: scheduled [/Pods/gRPC-Core/src/core/lib/surface/call.cc:1208]

D0723 12:47:28.184620000 123145435414528 call.cc:482]                  CQ:0x104700290   ref 0 -> 1 bind

I0723 12:47:28.184624000 123145435414528 ev_posix.cc:335]              (polling-api) pollset_add_fd(0x104700398, 9)

E0723 12:47:28.184627000 123145435414528 sync_posix.cc:85]             assertion failed: pthread_mutex_lock(mu) == 0

(lldb)

Environment

Key
Value




OS Version
10.14.5


Swift Version
5.0


Xcode Version
10.2


gRPC-Swift Version
0.9.1


protoc Version
3.6.0


protoc-gen-swift Version
1.5.0


protoc-gen-swiftgrpc Version
0.9.1



  

[MrMage]

Same as #325. Feel free to try fixing this, or use -1 (infinite timeout) to work around this.