OK, what's in the rest of the client log? The earlier part probably shows what happened when it tried to establish a connection to the server.
On Mon, May 3, 2021 at 12:27 PM Chris Tyler <[email protected]> wrote: > Michael, > > Thanks for the response. I did run client tracing as well. Again, after > getting several QUEUE_TIMEOUTs, I am getting a Deadline Exceeded. I even > bumped it up to 10 seconds, but continue to get that. I’m now running this > in minikube and still getting the same errors. > > I0503 14:19:15.964035000 4431523328 completion_queue.cc:960] > grpc_completion_queue_next(cq=0x10540bd90, deadline=gpr_timespec { tv_sec: > -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0x0) > I0503 14:19:15.964050000 4431523328 completion_queue.cc:1060] > RETURN_EVENT[0x10540bd90]: QUEUE_TIMEOUT > I0503 14:19:15.964205000 4431523328 completion_queue.cc:960] > grpc_completion_queue_next(cq=0x10540bd90, deadline=gpr_timespec { tv_sec: > -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0x0) > I0503 14:19:15.964213000 4431523328 completion_queue.cc:1060] > RETURN_EVENT[0x10540bd90]: QUEUE_TIMEOUT > I0503 14:19:15.964331000 4431523328 completion_queue.cc:960] > grpc_completion_queue_next(cq=0x10540bd90, deadline=gpr_timespec { tv_sec: > -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0x0) > I0503 14:19:15.964337000 4431523328 completion_queue.cc:1060] > RETURN_EVENT[0x10540bd90]: QUEUE_TIMEOUT > I0503 14:19:15.964476000 4431523328 completion_queue.cc:960] > grpc_completion_queue_next(cq=0x10540bd90, deadline=gpr_timespec { tv_sec: > -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0x0) > I0503 14:19:15.964482000 4431523328 completion_queue.cc:1060] > RETURN_EVENT[0x10540bd90]: QUEUE_TIMEOUT > I0503 14:19:15.964848000 4431523328 completion_queue.cc:960] > grpc_completion_queue_next(cq=0x10540bd90, deadline=gpr_timespec { tv_sec: > -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0x0) > I0503 14:19:15.964860000 4431523328 completion_queue.cc:1060] > RETURN_EVENT[0x10540bd90]: QUEUE_TIMEOUT > I0503 14:19:15.965061000 4431523328 completion_queue.cc:960] > grpc_completion_queue_next(cq=0x10540bd90, deadline=gpr_timespec { tv_sec: > -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0x0) > I0503 14:19:15.965072000 4431523328 completion_queue.cc:1060] > RETURN_EVENT[0x10540bd90]: QUEUE_TIMEOUT > I0503 14:19:15.965181000 4431523328 completion_queue.cc:960] > grpc_completion_queue_next(cq=0x10540bd90, deadline=gpr_timespec { tv_sec: > -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0x0) > I0503 14:19:15.965188000 4431523328 completion_queue.cc:1060] > RETURN_EVENT[0x10540bd90]: QUEUE_TIMEOUT > I0503 14:19:15.965355000 4431523328 completion_queue.cc:960] > grpc_completion_queue_next(cq=0x10540bd90, deadline=gpr_timespec { tv_sec: > -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0x0) > I0503 14:19:15.965367000 4431523328 completion_queue.cc:1060] > RETURN_EVENT[0x10540bd90]: QUEUE_TIMEOUT > I0503 14:19:15.965429000 4431523328 completion_queue.cc:960] > grpc_completion_queue_next(cq=0x10540bd90, deadline=gpr_timespec { tv_sec: > -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0x0) > I0503 14:19:15.965435000 4431523328 completion_queue.cc:1060] > RETURN_EVENT[0x10540bd90]: QUEUE_TIMEOUT > I0503 14:19:15.968316000 4431523328 completion_queue.cc:960] > grpc_completion_queue_next(cq=0x10540bd90, deadline=gpr_timespec { tv_sec: > -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0x0) > I0503 14:19:15.968334000 4431523328 completion_queue.cc:1060] > RETURN_EVENT[0x10540bd90]: QUEUE_TIMEOUT > I0503 14:19:15.968527000 4431523328 completion_queue.cc:960] > grpc_completion_queue_next(cq=0x10540bd90, deadline=gpr_timespec { tv_sec: > -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0x0) > I0503 14:19:15.968540000 4431523328 completion_queue.cc:1060] > RETURN_EVENT[0x10540bd90]: QUEUE_TIMEOUT > I0503 14:19:15.968594000 4431523328 completion_queue.cc:960] > grpc_completion_queue_next(cq=0x10540bd90, deadline=gpr_timespec { tv_sec: > -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0x0) > I0503 14:19:15.968602000 4431523328 completion_queue.cc:1060] > RETURN_EVENT[0x10540bd90]: QUEUE_TIMEOUT > I0503 14:19:17.191481000 4431523328 completion_queue.cc:960] > grpc_completion_queue_next(cq=0x10540bd90, deadline=gpr_timespec { tv_sec: > -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0x0) > I0503 14:19:17.191517000 4431523328 completion_queue.cc:1060] > RETURN_EVENT[0x10540bd90]: QUEUE_TIMEOUT > I0503 14:19:17.191549000 4431523328 completion_queue.cc:960] > grpc_completion_queue_next(cq=0x10540bd90, deadline=gpr_timespec { tv_sec: > -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0x0) > I0503 14:19:17.191557000 4431523328 completion_queue.cc:1060] > RETURN_EVENT[0x10540bd90]: QUEUE_TIMEOUT > I0503 14:19:18.012466000 4431523328 client_channel.cc:3663] > chand=0x10587d860 calld=0x10587c630: cancelling queued pick: > error={"created":"@1620069558.012433000","description":"Deadline > Exceeded","file":"../deps/grpc/src/core/ext/filters/deadline/ > deadline_filter.cc","file_line":69,"grpc_status":4} self=0x105437f80 > calld->pick_canceller=0x105437f80 > I0503 14:19:18.012498000 4431523328 client_channel.cc:3687] > chand=0x10587d860 calld=0x10587c630: removing from queued picks list > I0503 14:19:18.012511000 4431523328 client_channel.cc:2359] > chand=0x10587d860 calld=0x10587c630: failing 1 pending batches: > {"created":"@1620069558.012433000","description":"Deadline > Exceeded","file":"../deps/grpc/src/core/ext/filters/deadline/ > deadline_filter.cc","file_line":69,"grpc_status":4} > I0503 14:19:18.012527000 4431523328 completion_queue.cc:682] > cq_end_op_for_next(cq=0x10540bd90, tag=0x105062dc0, > error={"created":"@1620069558.012433000","description":"Deadline > Exceeded","file":"../deps/grpc/src/core/ext/filters/deadline/ > deadline_filter.cc","file_line":69,"grpc_status":4}, done=0x1082b5be0, > done_arg=0x10587cb10, storage=0x10587cb60) > E0503 14:19:18.012535000 4431523328 completion_queue.cc:685] > Operation failed: tag=0x105062dc0, > error={"created":"@1620069558.012433000","description":"Deadline > Exceeded","file":"../deps/grpc/src/core/ext/filters/deadline/ > deadline_filter.cc","file_line":69,"grpc_status":4} > I0503 14:19:18.012546000 4431523328 call.cc:626] > OP[client_idle:0x10587c5f0]: SEND_MESSAGE:flags=0x00000000:len=22 > I0503 14:19:18.012554000 4431523328 channel_stack.cc:226] > OP[client-channel:0x10587c608]: SEND_MESSAGE:flags=0x00000000:len=22 > I0503 14:19:18.012561000 4431523328 client_channel.cc:2249] > chand=0x10587d860 calld=0x10587c630: adding pending batch at index 1 > I0503 14:19:18.012604000 4431523328 client_channel.cc:2083] > chand=0x10587d860 calld=0x10587c630: saved batch, yielding call combiner > I0503 14:19:18.012615000 4431523328 call.cc:626] > OP[client_idle:0x10587c5f0]: SEND_TRAILING_METADATA{} > RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA > I0503 14:19:18.012624000 4431523328 channel_stack.cc:226] > OP[client-channel:0x10587c608]: SEND_TRAILING_METADATA{} > RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA > I0503 14:19:18.012630000 4431523328 client_channel.cc:2249] > chand=0x10587d860 calld=0x10587c630: adding pending batch at index 2 > I0503 14:19:18.012636000 4431523328 client_channel.cc:2083] > chand=0x10587d860 calld=0x10587c630: saved batch, yielding call combiner > I0503 14:19:18.012643000 4431523328 client_channel.cc:2035] > chand=0x10587d860 calld=0x10587c630: recording > cancel_error={"created":"@1620069558.012433000","description":"Deadline > Exceeded","file":"../deps/grpc/src/core/ext/filters/deadline/ > deadline_filter.cc","file_line":69,"grpc_status":4} > I0503 14:19:18.012667000 4431523328 client_channel.cc:2359] > chand=0x10587d860 calld=0x10587c630: failing 2 pending batches: > {"created":"@1620069558.012433000","description":"Deadline > Exceeded","file":"../deps/grpc/src/core/ext/filters/deadline/ > deadline_filter.cc","file_line":69,"grpc_status":4} > I0503 14:19:18.012678000 4431523328 call.cc:626] > OP[client_idle:0x10587c5f0]: > CANCEL:{"created":"@1620069558.012433000","description":"Deadline > Exceeded","file":"../deps/grpc/src/core/ext/filters/deadline/ > deadline_filter.cc","file_line":69,"grpc_status":4} > I0503 14:19:18.012686000 4431523328 channel_stack.cc:226] > OP[client-channel:0x10587c608]: > CANCEL:{"created":"@1620069558.012433000","description":"Deadline > Exceeded","file":"../deps/grpc/src/core/ext/filters/deadline/ > deadline_filter.cc","file_line":69,"grpc_status":4} > I0503 14:19:18.012969000 4431523328 client_channel.cc:2016] > chand=0x10587d860 calld=0x10587c630: failing batch with error: > {"created":"@1620069558.012433000","description":"Deadline > Exceeded","file":"../deps/grpc/src/core/ext/filters/deadline/ > deadline_filter.cc","file_line":69,"grpc_status":4} > I0503 14:19:18.012998000 4431523328 completion_queue.cc:682] > cq_end_op_for_next(cq=0x10540bd90, tag=0x10510f120, > error={"created":"@1620069558.012433000","description":"Deadline > Exceeded","file":"../deps/grpc/src/core/ext/filters/deadline/ > deadline_filter.cc","file_line":69,"grpc_status":4}, done=0x1082b5be0, > done_arg=0x10587cbf0, storage=0x10587cc40) > E0503 14:19:18.013008000 4431523328 completion_queue.cc:685] > Operation failed: tag=0x10510f120, > error={"created":"@1620069558.012433000","description":"Deadline > Exceeded","file":"../deps/grpc/src/core/ext/filters/deadline/ > deadline_filter.cc","file_line":69,"grpc_status":4} > D0503 14:19:18.013018000 4431523328 call.cc:733] > set_final_status CLI > D0503 14:19:18.013024000 4431523328 call.cc:734] > {"created":"@1620069558.012433000","description":"Deadline > Exceeded","file":"../deps/grpc/src/core/ext/filters/deadline/ > deadline_filter.cc","file_line":69,"grpc_status":4} > I0503 14:19:18.013034000 4431523328 completion_queue.cc:682] > cq_end_op_for_next(cq=0x10540bd90, tag=0x1051100a0, error="No Error", > done=0x1082b5be0, done_arg=0x10587ccd0, storage=0x10587cd20) > I0503 14:19:18.013046000 4431523328 completion_queue.cc:960] > grpc_completion_queue_next(cq=0x10540bd90, deadline=gpr_timespec { tv_sec: > -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0x0) > I0503 14:19:18.013118000 4431523328 completion_queue.cc:1060] > RETURN_EVENT[0x10540bd90]: OP_COMPLETE: tag:0x105062dc0 ERROR > I0503 14:19:18.013290000 4431523328 metadata_array.cc:34] > grpc_metadata_array_destroy(array=0x1050619d8) > I0503 14:19:18.013306000 4431523328 completion_queue.cc:960] > grpc_completion_queue_next(cq=0x10540bd90, deadline=gpr_timespec { tv_sec: > -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0x0) > I0503 14:19:18.013316000 4431523328 completion_queue.cc:1060] > RETURN_EVENT[0x10540bd90]: OP_COMPLETE: tag:0x10510f120 ERROR > I0503 14:19:18.013449000 4431523328 completion_queue.cc:960] > grpc_completion_queue_next(cq=0x10540bd90, deadline=gpr_timespec { tv_sec: > -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0x0) > I0503 14:19:18.013469000 4431523328 completion_queue.cc:1060] > RETURN_EVENT[0x10540bd90]: OP_COMPLETE: tag:0x1051100a0 OK > Error: 4 DEADLINE_EXCEEDED: Deadline Exceeded > at Object.exports.createStatusError > (/Users/canyonman/Development/BlockSpaces/connect/test/node_modules/grpc > /src/common.js:91:15) > at Object.onReceiveStatus > (/Users/canyonman/Development/BlockSpaces/connect/test/node_modules/grpc > /src/client_interceptors.js:1209:28) > at InterceptingListener._callNext > (/Users/canyonman/Development/BlockSpaces/connect/test/node_modules/grpc > /src/client_interceptors.js:568:42) > at InterceptingListener.onReceiveStatus > (/Users/canyonman/Development/BlockSpaces/connect/test/node_modules/grpc > /src/client_interceptors.js:618:8) > at callback > (/Users/canyonman/Development/BlockSpaces/connect/test/node_modules/grpc/src/client_interceptors.js:847:24) > { > code: 4, > metadata: Metadata { _internal_repr: {}, flags: 0 }, > details: 'Deadline Exceeded' > } > > > > Have a blessed day, > > Chris Tyler > CTO | BlockSpaces, Inc. > > > > 214.673.0483 <callto:2146730483> > [email protected] > > <https://twitter.com/chrisatyler> <https://linkedin.com/in/chrisatyler> > > This email and any files transmitted with it are confidential and intended > solely for the use of the individual or entity to whom they are addressed. > If you have received this email in error, please notify the system manager. > This message contains confidential information and is intended only for the > individual named. If you are not the named addressee, you should not > disseminate, distribute or copy this email. Please notify the sender > immediately by email if you have received this email by mistake and delete > this email from your system. If you are not the intended recipient, you are > notified that disclosing, copying, distributing or taking any action in > reliance on the contents of this information is strictly prohibited. > > On May 3, 2021, at 1:10 PM, Michael Lumish <[email protected]> wrote: > > Those QUEUE_TIMEOUT events don't really mean anything. They just show the > library polling for new events and not finding any at that time. If there's > nothing else in the log, that probably implies that the client can't > establish a connection to the server at all. If you enable tracing on the > client, you may get a better idea of what is going wrong. > > On Sat, May 1, 2021 at 1:51 AM Chris Tyler <[email protected]> > wrote: > >> I have created a gRPC client/server for processing Unary requests. I have >> had it working fine on my laptop. Now, I am working to deploy it to a >> Kubernetes cluster in IBM Cloud. The Deployment succeeds and the Service is >> running. I've tried this with both LoadBalancer and NodePort service types. >> >> I have enabled GRPC_TRACE=all and GRPC_VERBOSITY=DEBUG. When the pod >> starts, I see the logs below. I get about 20 repetitions of >> RETURN_EVENT...QUEUE_TIMEOUT. When I make a request using grpcurl, I get >> the message *transport is closing. * >> >> Currently, I'm using an insecure credentials connection. >> >> I have poured over a ton of posts around K8s and gRPC. It seemed pretty >> straight forward, but I'm struggling to get this to work. Any help would be >> greatly appreciated. >> >> Log file >> D0501 07:53:17.904046507 20 dns_resolver.cc:294] Using >> native dns resolver >> I0501 07:53:17.904189226 20 timer_manager.cc:88] Spawn timer >> thread >> I0501 07:53:17.904274322 20 init.cc:164] >> grpc_init(void) >> I0501 07:53:17.904358489 35 timer_manager.cc:250] timers not >> checked: expect another thread to >> I0501 07:53:17.904396913 35 timer_manager.cc:197] sleep until >> kicked >> I0501 07:53:17.904765647 20 completion_queue.cc:501] >> grpc_completion_queue_create_internal(completion_type=0, polling_type=0) >> I0501 07:53:18.310402717 20 server.cc:1021] >> grpc_server_create(0x55a6d0a0ad40, 0) >> I0501 07:53:18.310629797 20 server.cc:1002] >> grpc_server_register_completion_queue(server=0x55a6d093a980, >> cq=0x55a6d0bce8a0, reserved=0) >> I0501 07:53:18.330949779 20 server_chttp2.cc:33] >> grpc_server_add_insecure_http2_port(server=0x55a6d093a980, addr= >> 0.0.0.0:50052) >> I0501 07:53:18.331257146 20 tcp_server_custom.cc:382] SERVER >> 0x55a6d0b09cc0 add_port [::]:50052 error="No Error" >> I0501 07:53:18.331726761 20 server.cc:1111] >> grpc_server_start(server=0x55a6d093a980) >> I0501 07:53:18.331884195 20 tcp_server_custom.cc:424] >> SERVER_START 0x55a6d0b09cc0 >> I0501 07:53:18.332028119 20 call_details.cc:31] >> grpc_call_details_init(cd=0x55a6d0ad8170) >> I0501 07:53:18.332155662 20 metadata_array.cc:29] >> grpc_metadata_array_init(array=0x55a6d0ad81d0) >> I0501 07:53:18.332369156 20 server.cc:1470] >> grpc_server_request_call(server=0x55a6d093a980, call=0x55a6d0ad8168, >> details=0x55a6d0ad8170, initial_metadata=0x55a6d0ad81d0, >> cq_bound_to_call=0x55a6d0bce8a0, cq_for_notification=0x55a6d0bce8a0, >> tag=0x55a6d0b73d60) >> I0501 07:53:18.334480815 20 credentials.cc:183] >> grpc_server_credentials_release(creds=0) >> I0501 07:53:18.334693475 20 completion_queue.cc:952] >> grpc_completion_queue_next(cq=0x55a6d0bce8a0, deadline=gpr_timespec { >> tv_sec: -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0) >> I0501 07:53:18.334835887 20 completion_queue.cc:1060] >> RETURN_EVENT[0x55a6d0bce8a0]: QUEUE_TIMEOUT >> I0501 07:53:18.335157812 20 completion_queue.cc:952] >> grpc_completion_queue_next(cq=0x55a6d0bce8a0, deadline=gpr_timespec { >> tv_sec: -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0) >> I0501 07:53:18.335308566 20 completion_queue.cc:1060] >> RETURN_EVENT[0x55a6d0bce8a0]: QUEUE_TIMEOUT >> I0501 07:53:25.872128754 20 completion_queue.cc:952] >> grpc_completion_queue_next(cq=0x55a6d0bce8a0, deadline=gpr_timespec { >> tv_sec: -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0) >> I0501 07:53:25.872209655 20 completion_queue.cc:1060] >> RETURN_EVENT[0x55a6d0bce8a0]: QUEUE_TIMEOUT >> I0501 07:53:25.872281900 20 completion_queue.cc:952] >> grpc_completion_queue_next(cq=0x55a6d0bce8a0, deadline=gpr_timespec { >> tv_sec: -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=0) >> >> >> -- >> You received this message because you are subscribed to the Google Groups >> "grpc.io" group. >> To unsubscribe from this group and stop receiving emails from it, send an >> email to [email protected]. >> To view this discussion on the web visit >> https://groups.google.com/d/msgid/grpc-io/2d7f941e-9148-4d6c-833b-1242f41a684dn%40googlegroups.com >> <https://groups.google.com/d/msgid/grpc-io/2d7f941e-9148-4d6c-833b-1242f41a684dn%40googlegroups.com?utm_medium=email&utm_source=footer> >> . >> > > -- You received this message because you are subscribed to the Google Groups "grpc.io" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]. To view this discussion on the web visit https://groups.google.com/d/msgid/grpc-io/CAPK2-4e5eQ0f6cNRV7eteOzu%2BLxseFF%3DR_0EioSHH5E%2BONKk2g%40mail.gmail.com.
smime.p7s
Description: S/MIME Cryptographic Signature
