Skip to content

Instantly share code, notes, and snippets.

@juandelacruz-calvo

juandelacruz-calvo/grpc.log

Created August 17, 2023 08:23
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save juandelacruz-calvo/3edcf5ffe58970150cd41747e63ee942 to your computer and use it in GitHub Desktop.
Save juandelacruz-calvo/3edcf5ffe58970150cd41747e63ee942 to your computer and use it in GitHub Desktop.
Download ZIP
gRPC 1.57.0 debug log
Raw
grpc.log
814850576-D0816 13:49:11.756364527 13 chttp2_transport.cc:2024] maybe_complete_recv_trailing_metadata cli=1 s=0x2f756c0 closure=(nil) read_closed=1 write_closed=1 0
814850749-I0816 13:49:11.756420511 13 tcp_posix.cc:670] TCP:0x2e81b30 notify_on_read
814850850-I0816 13:49:11.756481056 13 promise_based_filter.cc:1594] CLI[compression:0x02f74f28] ClientCallData.RecvInitialMetadataReady has_promise=true sent_initial_state=FORWARDED recv_trailing_state=FORWARDED captured={} recv_initial_metadata=HOOKED_AND_GOT_PIPE error:OK md:PeerString: ipv4:127.0.0.1:10001, :status: 200, content-type: application/grpc, GrpcStatusFromWire: true, grpc-accept-encoding: identity, deflate, gzip, x-envoy-upstream-service-time: 26, date: Wed, 16 Aug 2023 13:49:11 GMT, server: envoy
814851371-I0816 13:49:11.756581821 13 promise_based_filter.cc:1026] CLI[compression:0x02f74f28] ClientCallData.PollContext.Run has_promise=true sent_initial_state=FORWARDED recv_trailing_state=FORWARDED captured={} recv_initial_metadata=COMPLETE_AND_GOT_PIPE
814851634-I0816 13:49:11.756633377 13 promise_based_filter.cc:490] CLI[compression:0x02f74f28] SendMessage.WakeInsideCombiner st=IDLE
814851773-I0816 13:49:11.756674769 13 promise_based_filter.cc:798] CLI[compression:0x02f74f28] ReceiveMessage.WakeInsideCombiner st=FORWARDED_BATCH push?=no next?=no allow_push_to_pipe=no
814851966-I0816 13:49:11.756723260 13 promise_based_filter.cc:1741] CLI[compression:0x02f74f28] ClientCallData.PollTrailingMetadata has_promise=true sent_initial_state=FORWARDED recv_trailing_state=FORWARDED captured={} recv_initial_metadata=COMPLETE_AND_PUSHED_TO_PIPE
814852240-I0816 13:49:11.756767469 13 promise_based_filter.cc:1112] CLI[compression:0x02f74f28] ClientCallData.PollContext.Run: poll=<<pending>>; has_promise=true sent_initial_state=FORWARDED recv_trailing_state=FORWARDED captured={} recv_initial_metadata=COMPLETE_AND_PUSHED_TO_PIPE
814852528-I0816 13:49:11.756812470 13 promise_based_filter.cc:1026] CLI[compression:0x02f74f28] ClientCallData.PollContext.Run has_promise=true sent_initial_state=FORWARDED recv_trailing_state=FORWARDED captured={} recv_initial_metadata=COMPLETE_AND_PUSHED_TO_PIPE
814852797-I0816 13:49:11.756860959 13 promise_based_filter.cc:490] CLI[compression:0x02f74f28] SendMessage.WakeInsideCombiner st=IDLE
814852936-I0816 13:49:11.756913043 13 promise_based_filter.cc:798] CLI[compression:0x02f74f28] ReceiveMessage.WakeInsideCombiner st=FORWARDED_BATCH push?=no next?=no allow_push_to_pipe=no
814853129-I0816 13:49:11.756959390 13 promise_based_filter.cc:1741] CLI[compression:0x02f74f28] ClientCallData.PollTrailingMetadata has_promise=true sent_initial_state=FORWARDED recv_trailing_state=FORWARDED captured={} recv_initial_metadata=RESPONDED
814853385-I0816 13:49:11.757002996 13 promise_based_filter.cc:1112] CLI[compression:0x02f74f28] ClientCallData.PollContext.Run: poll=<<pending>>; has_promise=true sent_initial_state=FORWARDED recv_trailing_state=FORWARDED captured={} recv_initial_metadata=RESPONDED
814853655-I0816 13:49:11.757050437 13 promise_based_filter.cc:1594] CLI[http-client:0x02f74ef8] ClientCallData.RecvInitialMetadataReady has_promise=true sent_initial_state=FORWARDED recv_trailing_state=FORWARDED captured={} recv_initial_metadata=HOOKED_AND_GOT_PIPE error:OK md:PeerString: ipv4:127.0.0.1:10001, :status: 200, content-type: application/grpc, GrpcStatusFromWire: true, grpc-accept-encoding: identity, deflate, gzip, x-envoy-upstream-service-time: 26, date: Wed, 16 Aug 2023 13:49:11 GMT, server: envoy
814854176-I0816 13:49:11.757094665 13 promise_based_filter.cc:1026] CLI[http-client:0x02f74ef8] ClientCallData.PollContext.Run has_promise=true sent_initial_state=FORWARDED recv_trailing_state=FORWARDED captured={} recv_initial_metadata=COMPLETE_AND_GOT_PIPE
814854439-I0816 13:49:11.757138558 13 promise_based_filter.cc:1741] CLI[http-client:0x02f74ef8] ClientCallData.PollTrailingMetadata has_promise=true sent_initial_state=FORWARDED recv_trailing_state=FORWARDED captured={} recv_initial_metadata=COMPLETE_AND_PUSHED_TO_PIPE
814854713-I0816 13:49:11.757182355 13 promise_based_filter.cc:1112] CLI[http-client:0x02f74ef8] ClientCallData.PollContext.Run: poll=<<pending>>; has_promise=true sent_initial_state=FORWARDED recv_trailing_state=FORWARDED captured={} recv_initial_metadata=COMPLETE_AND_PUSHED_TO_PIPE
814855001-I0816 13:49:11.757225815 13 promise_based_filter.cc:1026] CLI[http-client:0x02f74ef8] ClientCallData.PollContext.Run has_promise=true sent_initial_state=FORWARDED recv_trailing_state=FORWARDED captured={} recv_initial_metadata=COMPLETE_AND_PUSHED_TO_PIPE
814855270-I0816 13:49:11.757271017 13 promise_based_filter.cc:1741] CLI[http-client:0x02f74ef8] ClientCallData.PollTrailingMetadata has_promise=true sent_initial_state=FORWARDED recv_trailing_state=FORWARDED captured={} recv_initial_metadata=RESPONDED
814855526-I0816 13:49:11.757313834 13 promise_based_filter.cc:1112] CLI[http-client:0x02f74ef8] ClientCallData.PollContext.Run: poll=<<pending>>; has_promise=true sent_initial_state=FORWARDED recv_trailing_state=FORWARDED captured={} recv_initial_metadata=RESPONDED
814855796-I0816 13:49:11.757357981 13 retry_filter_legacy_call_data.cc:839] chand=0x2f62c80 calld=0x2f73ea0 attempt=0x2f9c060 batch_data=0x2f74700: got recv_initial_metadata_ready, error=OK
814855982-I0816 13:49:11.757401729 13 retry_filter_legacy_call_data.cc:1967] chand=0x2f62c80 calld=0x2f73ea0: committing retries
814856107-I0816 13:49:11.757444305 13 retry_filter_legacy_call_data.cc:1766] chand=0x2f62c80 calld=0x2f73ea0: destroying send_initial_metadata
814856246-I0816 13:49:11.757488233 13 retry_filter_legacy_call_data.cc:1775] chand=0x2f62c80 calld=0x2f73ea0: destroying send_messages[0]
814856380-I0816 13:49:11.757549024 13 retry_filter_legacy_call_data.cc:1785] chand=0x2f62c80 calld=0x2f73ea0: destroying send_trailing_metadata
814856520-I0816 13:49:11.757609190 13 retry_filter_legacy_call_data.cc:244] chand=0x2f62c80 calld=0x2f73ea0 attempt=0x2f9c060: retry state no longer needed; moving LB call to parent and unreffing the call attempt
814856729-I0816 13:49:11.757652159 13 retry_filter_legacy_call_data.cc:1949] chand=0x2f62c80 calld=0x2f73ea0: invoking recv_initial_metadata_ready for pending batch at index 0
814856901-D0816 13:49:11.757702935 13 call.cc:664] BATCH:0x2f73a90 COMPLETE:{kRecvInitialMetadata} REMAINING:{kRecvMessage,kRecvTrailingMetadata} (tag:0x7f8bd0472a90)
814857089-I0816 13:49:11.757746289 13 promise_based_filter.cc:700] CLI[compression:0x02f74f28] ReceiveMessage.OnComplete st=FORWARDED_BATCH status=OK
814857244-I0816 13:49:11.757788864 13 promise_based_filter.cc:1026] CLI[compression:0x02f74f28] ClientCallData.PollContext.Run has_promise=true sent_initial_state=FORWARDED recv_trailing_state=FORWARDED captured={} recv_initial_metadata=RESPONDED
814857495-I0816 13:49:11.757835218 13 promise_based_filter.cc:490] CLI[compression:0x02f74f28] SendMessage.WakeInsideCombiner st=IDLE
814857634-I0816 13:49:11.757877992 13 promise_based_filter.cc:798] CLI[compression:0x02f74f28] ReceiveMessage.WakeInsideCombiner st=BATCH_COMPLETED push?=no next?=no allow_push_to_pipe=yes
814857828-I0816 13:49:11.757924187 13 compression_filter.cc:172] DecompressMessage: len=439 max=4194304 alg=0
814857945-I0816 13:49:11.757968820 13 promise_based_filter.cc:891] CLI[compression:0x02f74f28] ReceiveMessage.WakeInsideCombiner next complete: got message new_state=PULLED_FROM_PIPE
814858133-I0816 13:49:11.758011137 13 promise_based_filter.cc:910] CLI[compression:0x02f74f28] ReceiveMessage.WakeInsideCombiner push complete
814858281-I0816 13:49:11.758054877 13 promise_based_filter.cc:1741] CLI[compression:0x02f74f28] ClientCallData.PollTrailingMetadata has_promise=true sent_initial_state=FORWARDED recv_trailing_state=FORWARDED captured={} recv_initial_metadata=RESPONDED
814858537-I0816 13:49:11.758098090 13 promise_based_filter.cc:1112] CLI[compression:0x02f74f28] ClientCallData.PollContext.Run: poll=<<pending>>; has_promise=true sent_initial_state=FORWARDED recv_trailing_state=FORWARDED captured={} recv_initial_metadata=RESPONDED
814858807-I0816 13:49:11.758150306 13 promise_based_filter.cc:700] CLI[message_size:0x02f74ec8] ReceiveMessage.OnComplete st=FORWARDED_BATCH status=OK
814858963-I0816 13:49:11.758192567 13 promise_based_filter.cc:1026] CLI[message_size:0x02f74ec8] ClientCallData.PollContext.Run has_promise=true sent_initial_state=FORWARDED recv_trailing_state=FORWARDED captured={}
814859183-I0816 13:49:11.758234666 13 promise_based_filter.cc:490] CLI[message_size:0x02f74ec8] SendMessage.WakeInsideCombiner st=IDLE
814859323-I0816 13:49:11.758277412 13 promise_based_filter.cc:798] CLI[message_size:0x02f74ec8] ReceiveMessage.WakeInsideCombiner st=BATCH_COMPLETED push?=no next?=no allow_push_to_pipe=yes
814859518-I0816 13:49:11.758322393 13 message_size_filter.cc:150] PBF_CLIENT[0x2f75190]: [message_size] [message_size] recv len:439 max:4194304
814859668-I0816 13:49:11.758365223 13 promise_based_filter.cc:891] CLI[message_size:0x02f74ec8] ReceiveMessage.WakeInsideCombiner next complete: got message new_state=PULLED_FROM_PIPE
814859857-I0816 13:49:11.758407669 13 promise_based_filter.cc:910] CLI[message_size:0x02f74ec8] ReceiveMessage.WakeInsideCombiner push complete
814860006-I0816 13:49:11.758449482 13 promise_based_filter.cc:1741] CLI[message_size:0x02f74ec8] ClientCallData.PollTrailingMetadata has_promise=true sent_initial_state=FORWARDED recv_trailing_state=FORWARDED captured={}
814860231-I0816 13:49:11.758492112 13 promise_based_filter.cc:1112] CLI[message_size:0x02f74ec8] ClientCallData.PollContext.Run: poll=<<pending>>; has_promise=true sent_initial_state=FORWARDED recv_trailing_state=FORWARDED captured={}
814860470-I0816 13:49:11.758560675 13 retry_filter_legacy_call_data.cc:938] chand=0x2f62c80 calld=0x2f73ea0 attempt=0x2f9c060 batch_data=0x2f74700: got recv_message_ready, error=OK
814860647-I0816 13:49:11.758610100 13 retry_filter_legacy_call_data.cc:1949] chand=0x2f62c80 calld=0x2f73ea0: invoking recv_message_ready for pending batch at index 0
814860810-D0816 13:49:11.758653136 13 call.cc:1384] tag:0x7f8bd0472a90 ReceivingStreamReady error=OK receiving_slice_buffer.has_value=1 recv_state=1
814860979-D0816 13:49:11.758697400 13 call.cc:664] BATCH:0x2f73a90 COMPLETE:{kRecvMessage} REMAINING:{kRecvTrailingMetadata} (tag:0x7f8bd0472a90)
814861146:I0816 13:49:11.758742057 13 promise_based_filter.cc:1792] CLI[compression:0x02f74f28] ClientCallData.RecvTrailingMetadataReady recv_trailing_state=FORWARDED error=OK md=grpc-message: Stream removed, grpc-status: 2
814861374:I0816 13:49:11.758785563 13 promise_based_filter.cc:741] CLI[compression:0x02f74f28] ReceiveMessage.Done st=IDLE md=grpc-message: Stream removed, grpc-status: 2
814861550:I0816 13:49:11.758832712 13 promise_based_filter.cc:447] CLI[compression:0x02f74f28] SendMessage.Done st=IDLE md=grpc-message: Stream removed, grpc-status: 2
814861723-I0816 13:49:11.758875195 13 promise_based_filter.cc:1026] CLI[compression:0x02f74f28] ClientCallData.PollContext.Run has_promise=true sent_initial_state=FORWARDED recv_trailing_state=COMPLETE captured={} recv_initial_metadata=RESPONDED
814861973-I0816 13:49:11.758917532 13 promise_based_filter.cc:490] CLI[compression:0x02f74f28] SendMessage.WakeInsideCombiner st=CANCELLED_BUT_NOT_YET_POLLED
814862136-I0816 13:49:11.758958885 13 promise_based_filter.cc:798] CLI[compression:0x02f74f28] ReceiveMessage.WakeInsideCombiner st=CANCELLED_WHILST_IDLE push?=no next?=no allow_push_to_pipe=yes
814862336-I0816 13:49:11.759001093 13 promise_based_filter.cc:1741] CLI[compression:0x02f74f28] ClientCallData.PollTrailingMetadata has_promise=true sent_initial_state=FORWARDED recv_trailing_state=COMPLETE captured={} recv_initial_metadata=RESPONDED
814862591:I0816 13:49:11.759044257 13 promise_based_filter.cc:1112] CLI[compression:0x02f74f28] ClientCallData.PollContext.Run: poll=grpc-message: Stream removed, grpc-status: 2; has_promise=true sent_initial_state=FORWARDED recv_trailing_state=COMPLETE captured={} recv_initial_metadata=RESPONDED
814862893:I0816 13:49:11.759088784 13 promise_based_filter.cc:447] CLI[compression:0x02f74f28] SendMessage.Done st=CANCELLED md=grpc-message: Stream removed, grpc-status: 2
814863071:I0816 13:49:11.759131231 13 promise_based_filter.cc:741] CLI[compression:0x02f74f28] ReceiveMessage.Done st=CANCELLED md=grpc-message: Stream removed, grpc-status: 2
814863252:I0816 13:49:11.759175128 13 promise_based_filter.cc:1792] CLI[http-client:0x02f74ef8] ClientCallData.RecvTrailingMetadataReady recv_trailing_state=FORWARDED error=OK md=grpc-message: Stream removed, grpc-status: 2
814863480-I0816 13:49:11.759227465 13 promise_based_filter.cc:1026] CLI[http-client:0x02f74ef8] ClientCallData.PollContext.Run has_promise=true sent_initial_state=FORWARDED recv_trailing_state=COMPLETE captured={} recv_initial_metadata=RESPONDED
814863730-I0816 13:49:11.759281182 13 promise_based_filter.cc:1741] CLI[http-client:0x02f74ef8] ClientCallData.PollTrailingMetadata has_promise=true sent_initial_state=FORWARDED recv_trailing_state=COMPLETE captured={} recv_initial_metadata=RESPONDED
814863985:I0816 13:49:11.759325858 13 promise_based_filter.cc:1112] CLI[http-client:0x02f74ef8] ClientCallData.PollContext.Run: poll=grpc-message: Stream removed, grpc-status: 2; has_promise=true sent_initial_state=FORWARDED recv_trailing_state=COMPLETE captured={} recv_initial_metadata=RESPONDED
814864287:I0816 13:49:11.759370493 13 promise_based_filter.cc:1792] CLI[message_size:0x02f74ec8] ClientCallData.RecvTrailingMetadataReady recv_trailing_state=FORWARDED error=OK md=grpc-message: Stream removed, grpc-status: 2
814864516:I0816 13:49:11.759412478 13 promise_based_filter.cc:741] CLI[message_size:0x02f74ec8] ReceiveMessage.Done st=IDLE md=grpc-message: Stream removed, grpc-status: 2
814864693:I0816 13:49:11.759455049 13 promise_based_filter.cc:447] CLI[message_size:0x02f74ec8] SendMessage.Done st=IDLE md=grpc-message: Stream removed, grpc-status: 2
814864867-I0816 13:49:11.759497251 13 promise_based_filter.cc:1026] CLI[message_size:0x02f74ec8] ClientCallData.PollContext.Run has_promise=true sent_initial_state=FORWARDED recv_trailing_state=COMPLETE captured={}
814865086-I0816 13:49:11.759564295 13 promise_based_filter.cc:490] CLI[message_size:0x02f74ec8] SendMessage.WakeInsideCombiner st=CANCELLED_BUT_NOT_YET_POLLED
814865250-I0816 13:49:11.759626935 13 promise_based_filter.cc:798] CLI[message_size:0x02f74ec8] ReceiveMessage.WakeInsideCombiner st=CANCELLED_WHILST_IDLE push?=no next?=no allow_push_to_pipe=yes
814865451-I0816 13:49:11.759669646 13 promise_based_filter.cc:1741] CLI[message_size:0x02f74ec8] ClientCallData.PollTrailingMetadata has_promise=true sent_initial_state=FORWARDED recv_trailing_state=COMPLETE captured={}
814865675:I0816 13:49:11.759713490 13 promise_based_filter.cc:1112] CLI[message_size:0x02f74ec8] ClientCallData.PollContext.Run: poll=grpc-message: Stream removed, grpc-status: 2; has_promise=true sent_initial_state=FORWARDED recv_trailing_state=COMPLETE captured={}
814865946:I0816 13:49:11.759757225 13 promise_based_filter.cc:447] CLI[message_size:0x02f74ec8] SendMessage.Done st=CANCELLED md=grpc-message: Stream removed, grpc-status: 2
814866125:I0816 13:49:11.759801804 13 promise_based_filter.cc:741] CLI[message_size:0x02f74ec8] ReceiveMessage.Done st=CANCELLED md=grpc-message: Stream removed, grpc-status: 2
814866307:I0816 13:49:11.759852841 13 promise_based_filter.cc:1792] CLI[client-auth-filter:0x02f74e98] ClientCallData.RecvTrailingMetadataReady recv_trailing_state=FORWARDED error=OK md=grpc-message: Stream removed, grpc-status: 2
814866542-I0816 13:49:11.759895559 13 promise_based_filter.cc:1026] CLI[client-auth-filter:0x02f74e98] ClientCallData.PollContext.Run has_promise=true sent_initial_state=FORWARDED recv_trailing_state=COMPLETE captured={}
814866767-I0816 13:49:11.759941729 13 promise_based_filter.cc:1741] CLI[client-auth-filter:0x02f74e98] ClientCallData.PollTrailingMetadata has_promise=true sent_initial_state=FORWARDED recv_trailing_state=COMPLETE captured={}
814866997:I0816 13:49:11.759985665 13 promise_based_filter.cc:1112] CLI[client-auth-filter:0x02f74e98] ClientCallData.PollContext.Run: poll=grpc-message: Stream removed, grpc-status: 2; has_promise=true sent_initial_state=FORWARDED recv_trailing_state=COMPLETE captured={}
814867274:I0816 13:49:11.760031098 13 promise_based_filter.cc:1792] CLI[authority:0x02f74e68] ClientCallData.RecvTrailingMetadataReady recv_trailing_state=FORWARDED error=OK md=grpc-message: Stream removed, grpc-status: 2
814867500-I0816 13:49:11.760073880 13 promise_based_filter.cc:1026] CLI[authority:0x02f74e68] ClientCallData.PollContext.Run has_promise=true sent_initial_state=FORWARDED recv_trailing_state=COMPLETE captured={}
814867716-I0816 13:49:11.760115760 13 promise_based_filter.cc:1741] CLI[authority:0x02f74e68] ClientCallData.PollTrailingMetadata has_promise=true sent_initial_state=FORWARDED recv_trailing_state=COMPLETE captured={}
814867937:I0816 13:49:11.760158089 13 promise_based_filter.cc:1112] CLI[authority:0x02f74e68] ClientCallData.PollContext.Run: poll=grpc-message: Stream removed, grpc-status: 2; has_promise=true sent_initial_state=FORWARDED recv_trailing_state=COMPLETE captured={}
814868205-I0816 13:49:11.760204836 13 client_channel.cc:3067] chand=0x2efc5e0 lb_call=0x2f74580: got recv_trailing_metadata_ready: error=OK call_attempt_tracer()=(nil) lb_subchannel_call_tracker_=(nil) failure_error_=OK
814868435-I0816 13:49:11.760248639 13 retry_filter_legacy_call_data.cc:1132] chand=0x2f62c80 calld=0x2f73ea0 attempt=0x2f9c060 batch_data=0x2f74700: got recv_trailing_metadata_ready, error=OK
814868623-I0816 13:49:11.760292241 13 retry_filter_legacy_call_data.cc:1159] chand=0x2f62c80 calld=0x2f73ea0 attempt=0x2f9c060: call finished, status=UNKNOWN server_pushback=N/A is_lb_drop=0 stream_network_state=N/A
814868835-I0816 13:49:11.760336184 13 retry_filter_legacy_call_data.cc:1949] chand=0x2f62c80 calld=0x2f73ea0: invoking recv_trailing_metadata_ready for pending batch at index 0
814869008-I0816 13:49:11.760380140 13 retry_filter_legacy_call_data.cc:1892] chand=0x2f62c80 calld=0x2f73ea0: clearing pending batch
814869137-I0816 13:49:11.760421151 13 retry_filter_legacy_call_data.cc:766] chand=0x2f62c80 calld=0x2f73ea0 attempt=0x2f9c060: destroying batch 0x2f74700
814869287-I0816 13:49:11.760463589 13 retry_filter_legacy_call_data.cc:177] chand=0x2f62c80 calld=0x2f73ea0 attempt=0x2f9c060: destroying call attempt
814869434-I0816 13:49:11.760508351 13 client_channel.cc:2353] chand=0x2efc5e0 calld=0x2f73920: got recv_trailing_metadata_ready: error=OK service_config_call_data=0x2f73df0
814869617-D0816 13:49:11.760564203 13 timer_generic.cc:442] TIMER 0x2f73a38: CANCEL pending=true
814869726:D0816 13:49:11.760637352 13 call.cc:1052] set_final_status CLI UNKNOWN:Error received from peer ipv4:127.0.0.1:10001 {grpc_message:"Stream removed", grpc_status:2, created_time:"2023-08-16T13:49:11.760609886+00:00"}
814869972-D0816 13:49:11.760689847 13 call.cc:664] BATCH:0x2f73a90 COMPLETE:{kRecvTrailingMetadata} REMAINING:{} (tag:0x7f8bd0472a90)
814870127-D0816 13:49:11.760745583 13 call.cc:1300] tag:0x7f8bd0472a90 batch_error=OK op: SEND_INITIAL_METADATA{:path: /spotify.commerce.invoicer.v1.InvoicerService/ListInvoices, grpc-timeout: @381742ms, WaitForReady: false, spotify-service-identity: eyJhbGciOiJSUzI1NiIsImtpZCI6IjdjOWM3OGUzYjAwZTFiYjA5MmQyNDZjODg3YjExMjIwYzg3YjdkMjAiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJodHRwOi8vcGF5bWVudC1pbnZvaWNlci1zZXJ2aWNlIiwiYXpwIjoiMTE1NDgwOTQyNjE4ODAwODA5NDkwIiwiZW1haWwiOiJzdWJzY3JpcHRpb25AZ2tlLXRlc3QtYWNjb3VudHMuaWFtLmdzZXJ2aWNlYWNjb3VudC5jb20iLCJlbWFpbF92ZXJpZmllZCI6dHJ1ZSwiZXhwIjoxNjkyMTk2OTczLCJpYXQiOjE2OTIxOTMzNzMsImlzcyI6Imh0dHBzOi8vYWNjb3VudHMuZ29vZ2xlLmNvbSIsInN1YiI6IjExNTQ4MDk0MjYxODgwMDgwOTQ5MCJ9.QahaP_XT2RjmMvf9RobL7qkA8T7gZWKRZ7mE4Xw4_3u5p0GsZv9F5_9OL73eZR8cMK9vwOUg7zoel8Xt6NaWfyyY5FWX0PgzdkXrJ94UI3l5l0LmU4VnnhyjiKwaIncFT1n1rYwdefP1XnVvQDbbMkJLqq0mrXje332rS-5IdtzhWf0Zqdo0eiBJdmg_FZF0g1ry6ukURUs3Se4nqzhhFsCXvPj3H7dn0znzXdHCmDOYmtvr_opYmNzWzeoZN1L5Y0MBwZiEMMQctIJOW4QRKB93W5-ZEpKBhIUfIUowOfAL4_aumDp619GkODLDBDKv4_N9uDtjLAPinHb_FF0hhA} SEND_MESSAGE(flag and length unknown, already orphaned) SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
814871329-I0816 13:49:11.760795565 13 completion_queue.cc:704] cq_end_op_for_next(cq=0x25ee5e0, tag=0x7f8bd0472a90, error=OK, done=0x7f8bdd64cc30, done_arg=0x2f73a90, storage=0x2f73ae0)
814871524-I0816 13:49:11.760846099 13 promise_based_filter.cc:1026] CLI[compression:0x02f74f28] ClientCallData.PollContext.Run has_promise=false sent_initial_state=FORWARDED recv_trailing_state=RESPONDED captured={} recv_initial_metadata=RESPONDED
814871776-I0816 13:49:11.760888617 13 promise_based_filter.cc:490] CLI[compression:0x02f74f28] SendMessage.WakeInsideCombiner st=CANCELLED
814871920-I0816 13:49:11.760930674 13 promise_based_filter.cc:798] CLI[compression:0x02f74f28] ReceiveMessage.WakeInsideCombiner st=CANCELLED push?=no next?=no allow_push_to_pipe=yes
814872108-I0816 13:49:11.760972875 13 promise_based_filter.cc:1026] CLI[http-client:0x02f74ef8] ClientCallData.PollContext.Run has_promise=false sent_initial_state=FORWARDED recv_trailing_state=RESPONDED captured={} recv_initial_metadata=RESPONDED
814872360-I0816 13:49:11.761015471 13 promise_based_filter.cc:1026] CLI[compression:0x02f74f28] ClientCallData.PollContext.Run has_promise=false sent_initial_state=FORWARDED recv_trailing_state=RESPONDED captured={} recv_initial_metadata=RESPONDED
814872612-I0816 13:49:11.761058036 13 promise_based_filter.cc:490] CLI[compression:0x02f74f28] SendMessage.WakeInsideCombiner st=CANCELLED
814872756-I0816 13:49:11.761100212 13 promise_based_filter.cc:798] CLI[compression:0x02f74f28] ReceiveMessage.WakeInsideCombiner st=CANCELLED push?=no next?=no allow_push_to_pipe=yes
814872944-I0816 13:49:11.761143412 13 promise_based_filter.cc:1026] CLI[message_size:0x02f74ec8] ClientCallData.PollContext.Run has_promise=false sent_initial_state=FORWARDED recv_trailing_state=RESPONDED captured={}
814873165-I0816 13:49:11.761185288 13 promise_based_filter.cc:490] CLI[message_size:0x02f74ec8] SendMessage.WakeInsideCombiner st=CANCELLED
814873310-I0816 13:49:11.761227589 13 promise_based_filter.cc:798] CLI[message_size:0x02f74ec8] ReceiveMessage.WakeInsideCombiner st=CANCELLED push?=no next?=no allow_push_to_pipe=yes
814873499-I0816 13:49:11.761273275 13 completion_queue.cc:1066] RETURN_EVENT[0x25ee5e0]: OP_COMPLETE: tag:0x7f8bd0472a90 OK
814873631-I0816 13:49:11.761365470 13 metadata_array.cc:35] grpc_metadata_array_destroy(array=0x7f8bd0385c98)
814873753-I0816 13:49:11.761432180 13 metadata_array.cc:35] grpc_metadata_array_destroy(array=0x7f8bd050f920)
814873875-I0816 13:49:11.761502813 13 call.cc:969] grpc_call_unref(c=0x2f72b50)
814873976-I0816 13:49:11.761567813 13 retry_filter_legacy_call_data.cc:1766] chand=0x2f62c80 calld=0x2f73ea0: destroying send_initial_metadata
814874115-I0816 13:49:11.761610506 13 retry_filter_legacy_call_data.cc:1785] chand=0x2f62c80 calld=0x2f73ea0: destroying send_trailing_metadata
814874255-I0816 13:49:11.761676189 13 completion_queue.cc:1395] grpc_completion_queue_shutdown(cq=0x25ee5e0)
814874372-I0816 13:49:11.761719715 13 completion_queue.cc:1400] grpc_completion_queue_destroy(cq=0x25ee5e0)
814874488-I0816 13:49:11.761761808 13 completion_queue.cc:1395] grpc_completion_queue_shutdown(cq=0x25ee5e0)
814874605-Traceback (most recent call last):
814874641- File "<console>", line 1, in <module>
...
814875340- File "/usr/src/app/.venv/lib/python3.8/site-packages/grpc/_interceptor.py", line 277, in __call__
814875441- response, ignored_call = self._with_call(
814875488- File "/usr/src/app/.venv/lib/python3.8/site-packages/grpc/_interceptor.py", line 332, in _with_call
814875591- return call.result(), call
814875623- File "/usr/src/app/.venv/lib/python3.8/site-packages/grpc/_channel.py", line 438, in result
814875718- raise self
814875734- File "/usr/src/app/.venv/lib/python3.8/site-packages/grpc/_interceptor.py", line 315, in continuation
814875839- response, call = self._thunk(new_method).with_call(
814875896- File "/usr/src/app/.venv/lib/python3.8/site-packages/grpc/_interceptor.py", line 343, in with_call
814875998- return self._with_call(
814876027- File "/usr/src/app/.venv/lib/python3.8/site-packages/grpc/_interceptor.py", line 332, in _with_call
814876130- return call.result(), call
814876162- File "/usr/src/app/.venv/lib/python3.8/site-packages/grpc/_channel.py", line 438, in result
814876257- raise self
814876273- File "/usr/src/app/.venv/lib/python3.8/site-packages/grpc/_interceptor.py", line 315, in continuation
814876378- response, call = self._thunk(new_method).with_call(
814876435- File "/usr/src/app/.venv/lib/python3.8/site-packages/grpc/_channel.py", line 1178, in with_call
814876534- return _end_unary_response_blocking(state, call, True, None)
814876600- File "/usr/src/app/.venv/lib/python3.8/site-packages/grpc/_channel.py", line 1004, in _end_unary_response_blocking
814876718- raise _InactiveRpcError(state) # pytype: disable=not-instantiable
814876790-grpc._channel._InactiveRpcError: <_InactiveRpcError of RPC that terminated with:
814876872- status = StatusCode.UNKNOWN
814876902: details = "Stream removed"
814876931: debug_error_string = "UNKNOWN:Error received from peer ipv4:127.0.0.1:10001 {grpc_message:"Stream removed", grpc_status:2, created_time:"2023-08-16T13:49:11.760609886+00:00"}"
814877109->
814877112->>>
814877118->>> I0816 13:49:11.777995639 99 timer_manager.cc:205] wait ended: was_timed:1 kicked:0
814877227-D0816 13:49:11.778091752 99 timer_generic.cc:696] TIMER CHECK BEGIN: now=380802 next=9223372036854775807 tls_min=380652 glob_min=380802
814877385-D0816 13:49:11.778135149 99 timer_generic.cc:596] .. shard[2]->min_deadline = 380802
814877494-D0816 13:49:11.778178125 99 timer_generic.cc:512] .. shard[2]: heap_empty=true
814877597-D0816 13:49:11.778221014 99 timer_generic.cc:483] .. shard[2]->queue_deadline_cap --> 381141
814877714-D0816 13:49:11.778264895 99 timer_generic.cc:556] .. shard[2] popped 0
814877809-D0816 13:49:11.778308412 99 timer_generic.cc:615] .. result --> 1, shard[2]->min_deadline 380802 --> 381142, now=380802
814877953-D0816 13:49:11.778352288 99 timer_generic.cc:722] TIMER CHECK END: r=1; next=381142
814878059-I0816 13:49:11.778395094 99 timer_manager.cc:189] sleep for a 340 milliseconds
814878160-I0816 13:49:12.117963501 99 timer_manager.cc:205] wait ended: was_timed:1 kicked:0
814878265-D0816 13:49:12.118066219 99 timer_generic.cc:696] TIMER CHECK BEGIN: now=381142 next=9223372036854775807 tls_min=380802 glob_min=381142
814878423-D0816 13:49:12.118123281 99 timer_generic.cc:596] .. shard[2]->min_deadline = 381142
814878532-D0816 13:49:12.118169280 99 timer_generic.cc:512] .. shard[2]: heap_empty=true
814878635-D0816 13:49:12.118218011 99 timer_generic.cc:483] .. shard[2]->queue_deadline_cap --> 381490
814878752-D0816 13:49:12.118277488 99 timer_generic.cc:556] .. shard[2] popped 0
814878847-D0816 13:49:12.118316851 99 timer_generic.cc:615] .. result --> 1, shard[2]->min_deadline 381142 --> 381491, now=381142
814878991-D0816 13:49:12.118372692 99 timer_generic.cc:722] TIMER CHECK END: r=1; next=381491
814879097-I0816 13:49:12.118420227 99 timer_manager.cc:189] sleep for a 349 milliseconds
814879198-I0816 13:49:12.466982640 99 timer_manager.cc:205] wait ended: was_timed:1 kicked:0
814879303-D0816 13:49:12.467090009 99 timer_generic.cc:696] TIMER CHECK BEGIN: now=381491 next=9223372036854775807 tls_min=381142 glob_min=381491
814879461-D0816 13:49:12.467153002 99 timer_generic.cc:596] .. shard[2]->min_deadline = 381491
814879570-D0816 13:49:12.467196075 99 timer_generic.cc:512] .. shard[2]: heap_empty=true
814879673-D0816 13:49:12.467234978 99 timer_generic.cc:483] .. shard[2]->queue_deadline_cap --> 381856
814879790-D0816 13:49:12.467278217 99 timer_generic.cc:556] .. shard[2] popped 0
814879885-D0816 13:49:12.467320118 99 timer_generic.cc:615] .. result --> 1, shard[2]->min_deadline 381491 --> 381857, now=381491
814880029-D0816 13:49:12.467369481 99 timer_generic.cc:722] TIMER CHECK END: r=1; next=381576
814880135-I0816 13:49:12.467411124 99 timer_manager.cc:189] sleep for a 85 milliseconds
814880235-I0816 13:49:12.551986415 99 timer_manager.cc:205] wait ended: was_timed:1 kicked:0
814880340-D0816 13:49:12.552095185 99 timer_generic.cc:696] TIMER CHECK BEGIN: now=381576 next=9223372036854775807 tls_min=381491 glob_min=381576
814880498-D0816 13:49:12.552154745 99 timer_generic.cc:596] .. shard[0]->min_deadline = 381576
814880607-D0816 13:49:12.552221215 99 timer_generic.cc:512] .. shard[0]: heap_empty=true
814880710-D0816 13:49:12.552263792 99 timer_generic.cc:483] .. shard[0]->queue_deadline_cap --> 382575
814880827-D0816 13:49:12.552319005 99 timer_generic.cc:556] .. shard[0] popped 0
814880922-D0816 13:49:12.552362294 99 timer_generic.cc:615] .. result --> 1, shard[0]->min_deadline 381576 --> 382576, now=381576
814881066-D0816 13:49:12.552414344 99 timer_generic.cc:512] .. shard[1]: heap_empty=true
814881169-D0816 13:49:12.552460842 99 timer_generic.cc:483] .. shard[1]->queue_deadline_cap --> 382575
814881286-D0816 13:49:12.552509150 99 timer_generic.cc:556] .. shard[1] popped 0
814881381-D0816 13:49:12.552604991 99 timer_generic.cc:615] .. result --> 1, shard[1]->min_deadline 381576 --> 382576, now=381576
814881525-D0816 13:49:12.552673582 99 timer_generic.cc:512] .. shard[3]: heap_empty=true
814881628-D0816 13:49:12.552713149 99 timer_generic.cc:483] .. shard[3]->queue_deadline_cap --> 382575
814881745-D0816 13:49:12.552776977 99 timer_generic.cc:556] .. shard[3] popped 0
814881840-D0816 13:49:12.552835823 99 timer_generic.cc:615] .. result --> 1, shard[3]->min_deadline 381576 --> 382576, now=381576
814881984-D0816 13:49:12.552892202 99 timer_generic.cc:512] .. shard[4]: heap_empty=true
814882087-D0816 13:49:12.552941892 99 timer_generic.cc:483] .. shard[4]->queue_deadline_cap --> 382575
814882204-D0816 13:49:12.552991148 99 timer_generic.cc:556] .. shard[4] popped 0
814882299-D0816 13:49:12.553034077 99 timer_generic.cc:615] .. result --> 1, shard[4]->min_deadline 381576 --> 382576, now=381576
814882443-D0816 13:49:12.553077094 99 timer_generic.cc:512] .. shard[5]: heap_empty=true
814882546-D0816 13:49:12.553119580 99 timer_generic.cc:483] .. shard[5]->queue_deadline_cap --> 382575
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment