grpc-dotnet icon indicating copy to clipboard operation
grpc-dotnet copied to clipboard

Published 20 hours ago • verified publisher icon grpc

DotNet client cannot connect to server, but grpcurl.exe can connect

Open axhero opened this issue 1 year ago • 4 comments

What version of gRPC and what language are you using?

C#; .NET 6 <PackageReference Include="Google.Protobuf" Version="3.23.4" /> <PackageReference Include="Grpc.Net.Client" Version="2.55.0" /> <PackageReference Include="Grpc.Tools" Version="2.56.0">

What operating system (Linux, Windows,...) and version?

Windows 10

What runtime / compiler are you using (e.g. .NET Core SDK version dotnet --info)

Compile: VS 2022 17.6.4 Runtime: .NET Desktop Runtime 6.0.19 Development PC:

C:\Users\aherold>dotnet --info
.NET SDK:
 Version:   7.0.306
 Commit:    f500069cb7

Laufzeitumgebung:
 OS Name:     Windows
 OS Version:  10.0.22621
 OS Platform: Windows
 RID:         win10-x64
 Base Path:   C:\Program Files\dotnet\sdk\7.0.306\

Host:
  Version:      7.0.9
  Architecture: x64
  Commit:       8e9a17b221

.NET SDKs installed:
  6.0.412 [C:\Program Files\dotnet\sdk]
  7.0.203 [C:\Program Files\dotnet\sdk]
  7.0.306 [C:\Program Files\dotnet\sdk]

.NET runtimes installed:
  Microsoft.AspNetCore.App 6.0.20 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 7.0.5 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 7.0.9 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 2.1.30 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 6.0.14 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 6.0.18 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 6.0.20 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 7.0.5 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 7.0.9 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.WindowsDesktop.App 6.0.20 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 7.0.5 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 7.0.9 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]

Other architectures found:
  x86   [C:\Program Files (x86)\dotnet]
    registered at [HKLM\SOFTWARE\dotnet\Setup\InstalledVersions\x86\InstallLocation]

Environment variables:
  Not set

global.json file:
  Not found

Learn more:
  https://aka.ms/dotnet/info

Download .NET:
  https://aka.ms/dotnet/download

What did you do?

We try to connect a gRPC Service (192.168.1.200:50055) with a small test client.

// address is "http://192.168.1.200:50055"
logger.LogInformation($"Try to connect service 'Server' at address '{address}'...");
using var channel = GrpcChannel.ForAddress(address, new GrpcChannelOptions { LoggerFactory = loggerFactory });
var client = new ServerCommunicationService.ServerCommunicationServiceClient(channel);

{
	string msg = $"Hello from '{Environment.MachineName}'";
	logger.LogInformation($"Try to call 'PingServiceAsync' with timeout '{timeout}' ms, message '{msg}'...");
	var request = new Server.Communication.Grpc.Interface.PingServiceRequest() { Name = Environment.MachineName };
	var reply = await client.PingServiceAsync(request, deadline: DateTime.UtcNow.AddMilliseconds(iTimeout));
	if (reply != null)
	{
		logger.LogInformation($"Call 'PingService':");
		logger.LogInformation($"PingMessage: {reply.PingMessage}");
		logger.LogInformation($"Messages: {string.Join("; ", reply.Messages.Select(x => $"Level:{x.Level}, ID: {x.ID}, Text:{x.Text}, Details: {x.Details}"))}");
	}
	else
	{
		logger.LogInformation($"return <null>");
	}
}

What did you expect to see?

A successful connection and the return value.

What did you see instead?

Get the system exception "The requested address is not valid in its context.". See log below. BUT... Ping to server is successful. Powershell "tnc 192.168.1.200 -port 50055" returns "TcpTestSucceeded=true". grpcurl.exe (https://github.com/fullstorydev/grpcurl) connection is successful and returns data:

PS D:\X-Update\CPV\grpcurl—1.8.7-windows—x86—64>.\grpcurl.exe —import-path .\3.1 —proto Server/Server.proto —plaintext `192.168.1.200:50055` Isra.CPV.Server.Conmunication.Grpc.Interface.Server.ServerCommunicationService/PingService
{
	"Messages" : [
	  {
	    "Details": "License File: /app/data/license/server.lic"
	  }
    ],
    "PingMessage": "Host 'cpvserver' running service Version '3.2.23.18501'"
}
PS D:\X-Update\CPV\grpcurl—1.8.7-windows—x86—64>

Here is the logging from grpc test client with TRACE enabled:

PS C:\Users\Sunny Kumar\Desktop\CPV 3.2\testclient03\publish> dotnet Isra.CPV.Tool.ServerServicePlainGrpcClient.dll -a http://192.168.1.200:50055
Application Configuration:
Logging:Console:LogLevel:Default = Trace
Logging:Console:LogLevel:Grpc = Trace
Logging:Console:LogLevel:Microsoft = Trace
Logging:LogLevel:Default = Trace
Logging:LogLevel:Grpc = Trace
Logging:LogLevel:Microsoft = Trace
Server:Call:All = false
Server:Grpc:Address = http://192.168.1.200:50055
Server:Grpc:Timeout = 30000

dbug: Isra.CPV.Tool.ServerServicePlainGrpcClient.Program[0]
      Test Debug Log
trce: Isra.CPV.Tool.ServerServicePlainGrpcClient.Program[0]
      Test Trace Log
info: Isra.CPV.Tool.ServerServicePlainGrpcClient.Program[0]
      Test Info Log
warn: Isra.CPV.Tool.ServerServicePlainGrpcClient.Program[0]
      Test Warning Log
fail: Isra.CPV.Tool.ServerServicePlainGrpcClient.Program[0]
      Test Error Log
crit: Isra.CPV.Tool.ServerServicePlainGrpcClient.Program[0]
      Test Critical Log
info: Isra.CPV.Tool.ServerServicePlainGrpcClient.Program[0]
      System.Environment.Version: 6.0.19
info: Isra.CPV.Tool.ServerServicePlainGrpcClient.Program[0]
      System.Runtime.InteropServices.RuntimeInformation.FrameworkDescription: .NET 6.0.19
info: Isra.CPV.Tool.ServerServicePlainGrpcClient.Program[0]
      Try to connect service 'Server' at address 'http://192.168.1.200:50055'...
info: Isra.CPV.Tool.ServerServicePlainGrpcClient.Program[0]
      Try to call 'PingServiceAsync' with timeout '30000' ms, message 'Hello from 'DESKTOP-VII28RU''...
dbug: Grpc.Net.Client.Internal.GrpcCall[1]
      Starting gRPC call. Method type: 'Unary', URI: 'http://192.168.1.200:50055/Isra.CPV.Server.Communication.Grpc.Interface.Server.ServerCommunicationService/PingService'.
trce: Grpc.Net.Client.Internal.GrpcCall[5]
      Starting deadline timeout. Duration: 00:00:29.9937267.
dbug: Grpc.Net.Client.Balancer.Subchannel[1]
      Subchannel id '1' created with addresses: 192.168.1.200:50055
trce: Grpc.Net.Client.Balancer.Subchannel[12]
      Subchannel id '1' state changed registration '1-1' created.
dbug: Grpc.Net.Client.Balancer.Internal.ConnectionManager[4]
      Channel picker updated.
trce: Grpc.Net.Client.Balancer.Subchannel[4]
      Subchannel id '1' connection requested.
dbug: Grpc.Net.Client.Balancer.Subchannel[11]
      Subchannel id '1' state changed to Connecting. Detail: 'Connection requested.'.
trce: Grpc.Net.Client.Balancer.Subchannel[14]
      Subchannel id '1' executing state changed registration '1-1'.
trce: Grpc.Net.Client.Balancer.PickFirstBalancer[1]
      Processing subchannel id '1' state changed to Connecting. Detail: 'Connection requested.'.
dbug: Grpc.Net.Client.Balancer.Internal.ConnectionManager[3]
      Channel state updated to Connecting.
trce: Grpc.Net.Client.Balancer.Internal.ConnectionManager[5]
      Pick started.
dbug: Grpc.Net.Client.Balancer.Internal.ConnectionManager[8]
      Picked queued.
trce: Grpc.Net.Client.Balancer.Internal.ConnectionManager[11]
      Waiting for a new picker.
trce: Grpc.Net.Client.Balancer.Subchannel[6]
      Subchannel id '1' connecting to transport.
trce: Grpc.Net.Client.Balancer.Internal.SocketConnectivitySubchannelTransport[1]
      Subchannel id '1' connecting socket to 192.168.1.200:50055.
dbug: Grpc.Net.Client.Balancer.Internal.SocketConnectivitySubchannelTransport[3]
      Subchannel id '1' error connecting to socket 192.168.1.200:50055.
      System.Net.Sockets.SocketException (10049): The requested address is not valid in its context.
         at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)
         at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token)
         at System.Net.Sockets.Socket.<ConnectAsync>g__WaitForConnectWithCancellation|277_0(AwaitableSocketAsyncEventArgs saea, ValueTask connectTask, CancellationToken cancellationToken)
         at Grpc.Net.Client.Balancer.Internal.SocketConnectivitySubchannelTransport.TryConnectAsync(ConnectContext context)
dbug: Grpc.Net.Client.Balancer.Subchannel[11]
      Subchannel id '1' state changed to TransientFailure. Detail: 'Error connecting to subchannel.'.
      System.Net.Sockets.SocketException (10049): The requested address is not valid in its context.
         at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)
         at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token)
         at System.Net.Sockets.Socket.<ConnectAsync>g__WaitForConnectWithCancellation|277_0(AwaitableSocketAsyncEventArgs saea, ValueTask connectTask, CancellationToken cancellationToken)
         at Grpc.Net.Client.Balancer.Internal.SocketConnectivitySubchannelTransport.TryConnectAsync(ConnectContext context)
trce: Grpc.Net.Client.Balancer.Subchannel[14]
      Subchannel id '1' executing state changed registration '1-1'.
trce: Grpc.Net.Client.Balancer.PickFirstBalancer[1]
      Processing subchannel id '1' state changed to TransientFailure. Detail: 'Error connecting to subchannel.'.
      System.Net.Sockets.SocketException (10049): The requested address is not valid in its context.
         at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)
         at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token)
         at System.Net.Sockets.Socket.<ConnectAsync>g__WaitForConnectWithCancellation|277_0(AwaitableSocketAsyncEventArgs saea, ValueTask connectTask, CancellationToken cancellationToken)
         at Grpc.Net.Client.Balancer.Internal.SocketConnectivitySubchannelTransport.TryConnectAsync(ConnectContext context)
dbug: Grpc.Net.Client.Balancer.Internal.ConnectionManager[3]
      Channel state updated to TransientFailure.
dbug: Grpc.Net.Client.Balancer.Internal.ConnectionManager[4]
      Channel picker updated.
trce: Grpc.Net.Client.Balancer.Internal.ConnectionManager[5]
      Pick started.
trce: Grpc.Net.Client.Balancer.Subchannel[7]
      Subchannel id '1' starting connect backoff of 00:00:01.1784883.
dbug: Grpc.Net.Client.Balancer.Internal.ConnectionManager[9]
      Picked failure with status: Status(StatusCode="Unavailable", Detail="Error connecting to subchannel.", DebugException="System.Net.Sockets.SocketException: The requested address is not valid in its context.")
dbug: Grpc.Net.Client.Internal.GrpcCall[6]
      Error starting gRPC call.
info: Grpc.Net.Client.Internal.GrpcCall[3]
      Call failed with gRPC error status. Status code: 'Unavailable', Message: 'Error connecting to subchannel.'.
      System.Net.Sockets.SocketException (10049): The requested address is not valid in its context.
         at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)
         at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token)
         at System.Net.Sockets.Socket.<ConnectAsync>g__WaitForConnectWithCancellation|277_0(AwaitableSocketAsyncEventArgs saea, ValueTask connectTask, CancellationToken cancellationToken)
         at Grpc.Net.Client.Balancer.Internal.SocketConnectivitySubchannelTransport.TryConnectAsync(ConnectContext context)
dbug: Grpc.Net.Client.Internal.GrpcCall[4]
      Finished gRPC call.
dbug: Grpc.Net.Client.Internal.GrpcCall[8]
      gRPC call canceled.
dbug: Grpc.Net.Client.Balancer.Subchannel[11]
      Subchannel id '1' state changed to Shutdown. Detail: 'Subchannel disposed.'.
trce: Grpc.Net.Client.Balancer.Subchannel[14]
      Subchannel id '1' executing state changed registration '1-1'.
trce: Grpc.Net.Client.Balancer.PickFirstBalancer[1]
      Processing subchannel id '1' state changed to Shutdown. Detail: 'Subchannel disposed.'.
dbug: Grpc.Net.Client.Balancer.Internal.ConnectionManager[3]
      Channel state updated to Shutdown.
dbug: Grpc.Net.Client.Balancer.Internal.ConnectionManager[4]
      Channel picker updated.
trce: Grpc.Net.Client.Balancer.Subchannel[13]
      Subchannel id '1' state changed registration '1-1' removed.
dbug: Grpc.Net.Client.Balancer.Subchannel[17]
      Subchannel id '1' canceling connect.
trce: Grpc.Net.Client.Balancer.Internal.SocketConnectivitySubchannelTransport[9]
      Subchannel id '1' disposing transport.
Program failed: Grpc.Core.RpcException: Status(StatusCode="Unavailable", Detail="Error connecting to subchannel.", DebugException="System.Net.Sockets.SocketException: The requested address is not valid in its context.")
 ---> System.Net.Sockets.SocketException (10049): The requested address is not valid in its context.
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token)
   at System.Net.Sockets.Socket.<ConnectAsync>g__WaitForConnectWithCancellation|277_0(AwaitableSocketAsyncEventArgs saea, ValueTask connectTask, CancellationToken cancellationToken)
   at Grpc.Net.Client.Balancer.Internal.SocketConnectivitySubchannelTransport.TryConnectAsync(ConnectContext context)
   --- End of inner exception stack trace ---
   at Grpc.Net.Client.Balancer.Internal.ConnectionManager.PickAsync(PickContext context, Boolean waitForReady, CancellationToken cancellationToken)
   at Grpc.Net.Client.Balancer.Internal.BalancerHttpHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
   at Grpc.Net.Client.Internal.GrpcCall`2.RunCall(HttpRequestMessage request, Nullable`1 timeout)
   at Isra.CPV.Tool.ServerServicePlainGrpcClient.Program.Main(String[] args) in C:\Workspaces\GPI_Tool_Framework_Main\Tool\Isra.CPV.Tool.ServerServicePlainGrpcClient\Program.cs:line 184
PS C:\Users\Sunny Kumar\Desktop\CPV 3.2\testclient03\publish>

Anything else we should know about your project / environment?

This issue occurs if the customer enables a Wifi adapter and allows connection from internet via TeamViewer. If the Wifi adapter is disabled the connection works well. An already connected gRPC client (which is opened before the Wifi adapter is enabled and connected to internet) hold the connection successfully. A newly created connection fails, but again with grpcurl.exe it works fine. We already checked firewall on/off; IP adapter settings (only enable IP4 feature) We are wondering that tnc tool and grpcurl.exe can connect but the dotnet test client cannot.

axhero avatar Jul 13 '23 14:07 axhero