Azure-functions-core-tools: Functions no longer working under WSL (Ubuntu 18.04) gRPC errors

[benc-uk]

Using WSL and Ubuntu 18.04

Running func start results in gRPC errors

[1/21/19 12:13:19 PM] Host initialized (308ms) 
[1/21/19 12:13:19 PM] Host started (340ms) 
[1/21/19 12:13:19 PM] Job host started
Hosting environment: Production 
Content root path: /home/ben/temp/functest
Now listening on: http://0.0.0.0:7071
Application started. Press Ctrl+C to shut down.
[1/21/19 12:13:19 PM] /usr/lib/azure-functions-core-tools/workers/node/worker-bundle.js:28464 
[1/21/19 12:13:19 PM]         throw new Error(`gRPC client connection info is missing or incorrect (${debugInfo.join(", ")}).`);
[1/21/19 12:13:20 PM]         ^ 
[1/21/19 12:13:20 PM] Error: gRPC client connection info is missing or incorrect ('port' is 0).
[1/21/19 12:13:20 PM] usage --host hostName --port portNumber --workerId workerId --requestId requestId --grpcMaxMessageLength grpcMaxMessageLength
[1/21/19 12:13:20 PM]     at Object.startNodeWorker (/usr/lib/azure-functions-core-tools/workers/node/worker-bundle.js:28464:15) 
[1/21/19 12:13:20 PM]     at Object.<anonymous> (/usr/lib/azure-functions-core-tools/workers/node/dist/src/nodejsWorker.js:48:8)
[1/21/19 12:13:20 PM]     at Module._compile (module.js:653:30) 
[1/21/19 12:13:20 PM]     at Object.Module._extensions..js (module.js:664:10)
[1/21/19 12:13:20 PM]     at Module.load (module.js:566:32) 
[1/21/19 12:13:20 PM]     at tryModuleLoad (module.js:506:12) 
[1/21/19 12:13:20 PM]     at Function.Module._load (module.js:498:3)
[1/21/19 12:13:20 PM]     at Function.Module.runMain (module.js:694:10)
[1/21/19 12:13:20 PM]     at startup (bootstrap_node.js:204:16) 
[1/21/19 12:13:20 PM]     at bootstrap_node.js:625:3
[1/21/19 12:13:20 PM] Language Worker Process exited. 
[1/21/19 12:13:20 PM] node exited with code 1
[1/21/19 12:13:20 PM]          throw new Error(`gRPC client connection info is missing or incorrect (${debugInfo.join(", ")}).`);,Error: gRPC client connection info is missing or incorrect ('port' is 0).
[1/21/19 12:13:20 PM] Starting language worker process:node  "/usr/lib/azure-functions-core-tools/workers/node/dist/src/nodejsWorker.js" --host 127.0.0.1 --port 0 --workerId 15dae68d-cf05-4302-a67e-f0182244b190 --requestId be4c4ca7-47b8-4b8e-aae3-f4f38876b4cc --grpcMaxMessageLength 134217728
[1/21/19 12:13:20 PM] node process with Id=490 started 
[1/21/19 12:13:20 PM] usage --host hostName --port portNumber --workerId workerId --requestId requestId --grpcMaxMessageLength grpcMaxMessageLength 
[1/21/19 12:13:20 PM] /usr/lib/azure-functions-core-tools/workers/node/worker-bundle.js:28464 
[1/21/19 12:13:20 PM]         throw new Error(`gRPC client connection info is missing or incorrect (${debugInfo.join(", ")}).`);
[1/21/19 12:13:20 PM] Language Worker Process exited.
[1/21/19 12:13:20 PM]         ^
[1/21/19 12:13:20 PM] node exited with code 1
[1/21/19 12:13:20 PM] Error: gRPC client connection info is missing or incorrect ('port' is 0).

This happens in my existing Function project (Node.js) and also creating a empty new project with func init and immediately running func start

Versions

Function CLI version: 2.3.199 (Installed with apt package)
Node version: 8.15.0
Dotnet Core version: 2.1.503
Windows 10 version: 1809
WSL distro: Ubuntu 18.04.1 LTS

[benc-uk]

I just tried with a Python (3.6) project and also got gRPC errors

[1/21/19 12:22:48 PM] Host initialized (369ms)
[1/21/19 12:22:48 PM] Host started (389ms) 
[1/21/19 12:22:48 PM] Job host started     
Hosting environment: Production 
Content root path: /home/ben/temp/fpy
Now listening on: http://0.0.0.0:7071
Application started. Press Ctrl+C to shut down. 

[1/21/19 12:22:53 PM] Host lock lease acquired by instance ID '000000000000000000000000A87B80B1'. 
[1/21/19 12:22:53 PM] Traceback (most recent call last):
[1/21/19 12:22:53 PM]   File "/usr/lib/azure-functions-core-tools/workers/python/worker.py", line 29, in main
[1/21/19 12:22:53 PM] Traceback (most recent call last):
[1/21/19 12:22:53 PM]     args.grpc_max_msg_len)[1/21/19 12:22:53 PM]   File "/usr/lib/azure-functions-core-tools/workers/python/worker.py", line 36, in <module>
[1/21/19 12:22:53 PM]   File "/home/ben/temp/fpy/pyenv/lib/python3.6/site-packages/azure/functions_worker/__init__.py", line 16, in start 
[1/21/19 12:22:53 PM]     main()
[1/21/19 12:22:53 PM]     host, port, worker_id, request_id, grpc_max_msg_len)) 
[1/21/19 12:22:53 PM]   File "/usr/lib/azure-functions-core-tools/workers/python/worker.py", line 29, in main
[1/21/19 12:22:53 PM]   File "/home/ben/temp/fpy/pyenv/lib/python3.6/site-packages/azure/functions_worker/aio_compat.py", line 49, in run
[1/21/19 12:22:53 PM]     args.grpc_max_msg_len)
[1/21/19 12:22:53 PM]     return loop.run_until_complete(main) 
[1/21/19 12:22:53 PM]   File "/usr/lib/python3.6/asyncio/base_events.py", line 473, in run_until_complete
[1/21/19 12:22:53 PM]   File "/home/ben/temp/fpy/pyenv/lib/python3.6/site-packages/azure/functions_worker/__init__.py", line 16, in start
[1/21/19 12:22:53 PM]     host, port, worker_id, request_id, grpc_max_msg_len))
[1/21/19 12:22:53 PM]     return future.result()
[1/21/19 12:22:53 PM]   File "/home/ben/temp/fpy/pyenv/lib/python3.6/site-packages/azure/functions_worker/__init__.py", line 8, in start_async
[1/21/19 12:22:53 PM]   File "/home/ben/temp/fpy/pyenv/lib/python3.6/site-packages/azure/functions_worker/aio_compat.py", line 49, in run
[1/21/19 12:22:53 PM]     return loop.run_until_complete(main) 
[1/21/19 12:22:53 PM]     connect_timeout=5.0, max_msg_len=grpc_max_msg_len)
[1/21/19 12:22:53 PM]   File "/usr/lib/python3.6/asyncio/base_events.py", line 473, in run_until_complete
[1/21/19 12:22:53 PM]   File "/home/ben/temp/fpy/pyenv/lib/python3.6/site-packages/azure/functions_worker/dispatcher.py", line 74, in connect 
[1/21/19 12:22:53 PM]     return future.result()
[1/21/19 12:22:53 PM]     await disp._grpc_connected_fut
[1/21/19 12:22:53 PM]   File "/home/ben/temp/fpy/pyenv/lib/python3.6/site-packages/azure/functions_worker/__init__.py", line 8, in start_async 
[1/21/19 12:22:53 PM] Language Worker Process exited.
[1/21/19 12:22:53 PM]     connect_timeout=5.0, max_msg_len=grpc_max_msg_len)
[1/21/19 12:22:53 PM] python exited with code 1 
[1/21/19 12:22:53 PM]  .
[1/21/19 12:22:53 PM]   File "/home/ben/temp/fpy/pyenv/lib/python3.6/site-packages/azure/functions_worker/dispatcher.py", line 74, in connect
[1/21/19 12:22:53 PM]   File "/home/ben/temp/fpy/pyenv/lib/python3.6/site-packages/azure/functions_worker/dispatcher.py", line 337, in __poll_grpc 
[1/21/19 12:22:53 PM]     await disp._grpc_connected_fut
[1/21/19 12:22:53 PM]     timeout=self._grpc_connect_timeout)

[benc-uk]

Just tried on a Ubuntu 18.04 virtual machine, and had no problems - so it seems 100% related to WSL

The root cause seems to be the port being zero e.g. "/usr/lib/azure-functions-core-tools/workers/node/dist/src/nodejsWorker.js" --host 127.0.0.1 --port 0 --workerId blahblah

When running on the VM and under PowerShell I see a randomly assigned port there, e.g. 46209

[benc-uk]

I've found the issue. It's in the azure-functions-host GrpcServer.cs
https://github.com/Azure/azure-functions-host/blob/398fef4f4487c6f966bafa3d620cd53a27c98b03/src/WebJobs.Script.Grpc/Server/GrpcServer.cs#L27
Where the unused port is picked for the gRPC server using ServerPort.PickUnused. There seems to be a bug the in gRPC Core library where this is returning 0 when running under WSL

I've created a simple .NET Core console app to replicate the problem. Running under WSL this prints First bound port is: 0

UPDATE: :warning: By upgrading my packages to Grpc.Core 1.17.0 the problem is resolved as per this fix https://github.com/grpc/grpc/pull/17193

using System;
using System.Linq;
using Grpc.Core;

namespace GRPC_Test
{
  class Program
  {
    static void Main(string[] args)
    {
      ChannelOption maxReceiveMessageLength = new ChannelOption(ChannelOptions.MaxReceiveMessageLength, 4000);
      ChannelOption maxSendMessageLength = new ChannelOption(ChannelOptions.MaxSendMessageLength, 4000);
      ChannelOption[] grpcChannelOptions = { maxReceiveMessageLength, maxSendMessageLength };

      Console.WriteLine("Creating server with ServerPort.PickUnused");
      Server server = new Server(grpcChannelOptions)
      {
        Ports = { new ServerPort("127.0.0.1", ServerPort.PickUnused, ServerCredentials.Insecure) }
      };

      Console.WriteLine("Number of ports: " + server.Ports.Count());
      Console.WriteLine("First bound port is: " + server.Ports.First().BoundPort);
    }
  }
}

[wpwoodjr]

Hi @benc-uk , how can I update my gRPC package for Azure Functions under WSL? Thanks!

[benc-uk]

I just upgraded to version 2.4.317 of the core tools under WSL. I noticed that this release updated the version of azure-functions-host to version 2.0.12303, and that version has the updated gRPC version (1.18.0) in order to fix this.

However when I start my functions I see the runtime version is still 2.0.12285.0 and I still get the same gRPC errors as before.

I updated my WSL version of the core tools using apt.
I downloaded the Windows version of the 2.4.317 tools as well, and the WebHost dll is still at 2.0.12285.0
I notice that the master branch has the version change but the 2.4.317 tag of the source does not have any change to the Azure.Functions.Cli.csproj file

Has there been a packaging issue?

$ func start
Azure Functions Core Tools (2.4.317 Commit hash: 63e1996b6c281079427e7c9b8a0a1c633988a195)
Function Runtime Version: 2.0.12285.0

throw new Error(`gRPC client connection info is missing or incorrect (${debugInfo.join(", ")}).`);,Error: gRPC client connection info is missing or incorrect ('port' is 0).

[benc-uk]

Any update? As the core-tools are still not usable under WSL

[wpwoodjr]

Can we get an update please?

[benc-uk]

Finally fixed with the 2.0.12309 release
Thanks