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]
<mailto:[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]
> <mailto:[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
> <http://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 <http://grpc.io/>" group.
> To unsubscribe from this group and stop receiving emails from it, send an
> email to [email protected]
> <mailto:[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/32D3BAEB-E389-4D1F-8DCE-3EDEACB9F25F%40blockspaces.io.
