The server side log tells you the connection is closed due to TLS failures.

The client is configured to _not_ to TLS, so it doesn't understand the 
handshake message, and will try to send plaintext. It only sees the 
connection is closed, but doesn't know why.
The client can only report TLS errors if it understands TLS. But an 
insecure client doesn't.

WithBlock() only changes whether Dial() will waits for connection to become 
READY, it doesn't change the connection behavior. With or without 
WithBlock(), the same failure would happen, and the same log would be 
printed.
Without WithBlock(), maybe things happened too fast that the client got 
killed before the logs were flushed?

On Tuesday, July 13, 2021 at 3:45:22 PM UTC-7 amits...@gmail.com wrote:

> On Tue, Jul 13, 2021 at 4:25 AM 'Menghan Li' via grpc.io
> <grp...@googlegroups.com> wrote:
> >
> > Yes, this is expected. The connection cannot be created, because the 
> server is expecting a handshake, but the client is not configured to do it.
> >
> > The only thing is, I would expect a better error message.
> > Can you check the client and server logs and see if there's any 
> information?
> > https://github.com/grpc/grpc-go#how-to-turn-on-logging
>
> On the server:
>
> WARNING: 2021/07/14 08:38:25 [core] grpc: Server.Serve failed to
> complete security handshake from "[::1]:56653": tls: first record does
> not look like a TLS handshake
>
> On the client:
>
> INFO: 2021/07/14 08:38:25 [core] parsed scheme: ""
> INFO: 2021/07/14 08:38:25 [core] scheme "" not registered, fallback to
> default scheme
> INFO: 2021/07/14 08:38:25 [core] ccResolverWrapper: sending update to
> cc: {[{localhost:50051 <nil> 0 <nil>}] <nil> <nil>}
> INFO: 2021/07/14 08:38:25 [core] ClientConn switching balancer to 
> "pick_first"
> INFO: 2021/07/14 08:38:25 [core] Channel switches to new LB policy 
> "pick_first"
> INFO: 2021/07/14 08:38:25 [core] Subchannel Connectivity change to 
> CONNECTING
> INFO: 2021/07/14 08:38:25 [core] blockingPicker: the picked transport
> is not ready, loop back to repick
> INFO: 2021/07/14 08:38:25 [core] Subchannel picks a new address
> "localhost:50051" to connect
> INFO: 2021/07/14 08:38:25 [core] pickfirstBalancer:
> UpdateSubConnState: 0x14000113d30, {CONNECTING <nil>}
> INFO: 2021/07/14 08:38:25 [core] Channel Connectivity change to CONNECTING
> INFO: 2021/07/14 08:38:25 [core] Subchannel Connectivity change to
> TRANSIENT_FAILURE
> INFO: 2021/07/14 08:38:25 [core] pickfirstBalancer:
> UpdateSubConnState: 0x14000113d30, {TRANSIENT_FAILURE connection
> closed}
> INFO: 2021/07/14 08:38:25 [core] Channel Connectivity change to
> TRANSIENT_FAILURE
>
> ----
> # My error logs
> 2021/07/14 08:38:25 Error getUser
> 2021/07/14 08:38:25 rpc error: code = Unavailable desc = connection closed
> ----
>
> INFO: 2021/07/14 08:38:25 [transport] transport: loopyWriter.run
> returning. connection error: desc = "transport is closing"
>
> The above client behavior is without WithBlock(). When I specify
> WithBlock(), the above connection attempt essentially continues (as
> expected - since it is a TRANSIENT_FAILURE).
>
> The interesting thing however which now explains my original query is
> when I insert a time.Sleep() between establishing the connection and
> calling the RPC method, i do see the above logs as well. My original
> confusion was that I should have got the error due to TLS before I
> made the RPC method, not when making the RPC method. However, I have
> got that clarified now with the time.Sleep(..) and the logging.
>
> Thanks. If there is any further investigation I can do, I would be keen to 
> know.
>
> Best Regards,
> Amit
>
>
>
> >
> > Thanks,
> > Menghan
> >
> > On Friday, July 2, 2021 at 1:26:50 AM UTC-7 amits...@gmail.com wrote:
> >>
> >> Hello all,
> >>
> >> I have a Go server configured to use self-signed TLS certs. When I
> >> specify the certificate to the client, it all works great.
> >>
> >> When I try to connect to the server over an insecure channel, it seems
> >> that the channel gets established, but i get an error when i make the
> >> RPC method call:
> >>
> >> 2021/07/02 17:37:04 Error getUser
> >> 2021/07/02 17:37:04 rpc error: code = Unavailable desc = connection 
> closed
> >>
> >> Is this expected?
> >>
> >> Thanks,
> >> Amit.
> >
> > --
> > 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 grpc-io+u...@googlegroups.com.
> > To view this discussion on the web visit 
> https://groups.google.com/d/msgid/grpc-io/c97f567d-45e8-476f-8e5a-f2142a24ef93n%40googlegroups.com
> .
>

-- 
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 grpc-io+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/grpc-io/bcedd55e-9bcc-40b6-9dd7-60c3c66355dbn%40googlegroups.com.

Reply via email to