`app:run --local` fails on wsl2 environments - [ERROR] Bind failed for TCP channel on endpoint [/172.17.0.1:3232]Bind failed

eliashussary commented 3 years ago

Describe the bug Running aio app run --local fails in wsl2 environments

I'm opening this issue for visibility. https://github.com/apache/openwhisk/issues/5108

To Reproduce Steps to reproduce the behavior:

In an aio project, run aio app run --local
aio errors out due to a port bind error
Check logs dist/openwhisk-local.log.txt
See error

Expected behavior openwhisk should successfully run locally.

Desktop (please complete the following information):

OS: Windows w/ WSL2 Ubuntu 20.04
Browser: n/a
Version:

➜  standalone-v1 java -jar openwhisk-standalone.jar --version
Git Commit - 6feda87

➜  ui.razzle git:(main) yarn aio info
yarn run v1.22.10
$ /home/elias/code/aem-react-aio-poc/ui.razzle/node_modules/.bin/aio info

  System:
    OS: Linux 5.4 Ubuntu 20.04.2 LTS (Focal Fossa)
    CPU: (16) x64 AMD Ryzen 9 4900HS with Radeon Graphics
    Memory: 8.87 GB / 12.02 GB
    Shell: 5.8 - /usr/bin/zsh
  Binaries:
    Node: 14.16.1 - /tmp/yarn--1619720402133-0.7115322482991213/node
    Yarn: 1.22.10 - /tmp/yarn--1619720402133-0.7115322482991213/yarn
    npm: 6.14.12 - ~/.nvm/versions/node/v14.16.1/bin/npm
  Virtualization:
    Docker: 20.10.5 - /usr/bin/docker
  npmGlobalPackages:
    @adobe/aio-cli: Not Found
  CLI plugins:
    @adobe/aio-cli 6.0.0 (core)
    @adobe/aio-cli-plugin-app 6.2.0 (core)
    @adobe/aio-cli-plugin-auth 2.4.1 (core)
    @adobe/aio-cli-plugin-certificate 0.2.1 (core)
    @adobe/aio-cli-plugin-config 2.3.0 (core)
    @adobe/aio-cli-plugin-console 3.3.0 (core)
    @adobe/aio-cli-plugin-events 1.1.0 (core)
    @adobe/aio-cli-plugin-info 1.1.1 (core)
    @adobe/aio-cli-plugin-runtime 3.1.0 (core)
    @oclif/plugin-autocomplete 0.3.0 (core)
    @oclif/plugin-help 2.2.3 (core)
    @oclif/plugin-not-found 1.2.4 (core)
    @oclif/plugin-plugins 1.10.0 (core)
    @oclif/plugin-warn-if-update-available 1.7.0 (core)
 ›   Warning: Node version not supported. Supported versions are 10 and 12
Done in 1.90s.

meryllblanchet commented 3 years ago

Hi @eliashussary , thanks for opening the issue. Adding @shazron for feedback.

Please note that we currently do not support Node 14 (ETA end of May). Can you reproduce with Node 12 LTS?

eliashussary commented 3 years ago

Hi @eliashussary , thanks for opening the issue. Adding @shazron for feedback.

Please note that we currently do not support Node 14 (ETA end of May). Can you reproduce with Node 12 LTS?

Yes the same issue occurs with Node 12.

eliashussary commented 3 years ago

@meryllblanchet here are the full logs under a node12 env;

➜  ui.razzle git:(main) yarn aio info
yarn run v1.22.10
$ /home/elias/code/aem-react-aio-poc/ui.razzle/node_modules/.bin/aio info

  System:
    OS: Linux 4.19 Ubuntu 20.04 LTS (Focal Fossa)
    CPU: (16) x64 AMD Ryzen 7 3700X 8-Core Processor
    Memory: 21.48 GB / 24.99 GB
    Shell: 5.8 - /usr/bin/zsh
  Binaries:
    Node: 12.21.0 - /tmp/yarn--1619789408696-0.6874909161505918/node
    Yarn: 1.22.10 - /tmp/yarn--1619789408696-0.6874909161505918/yarn
    npm: 7.6.3 - ~/.yarn/bin/npm
  Virtualization:
    Docker: 20.10.5 - /usr/bin/docker
  npmGlobalPackages:
    @adobe/aio-cli: 6.0.0
  CLI plugins:
    @adobe/aio-cli 6.0.0 (core)
    @adobe/aio-cli-plugin-app 6.2.0 (core)
    @adobe/aio-cli-plugin-auth 2.4.1 (core)
    @adobe/aio-cli-plugin-certificate 0.3.0 (user)
    @adobe/aio-cli-plugin-config 2.3.0 (core)
    @adobe/aio-cli-plugin-console 3.3.0 (core)
    @adobe/aio-cli-plugin-events 1.1.0 (core)
    @adobe/aio-cli-plugin-info 1.1.1 (core)
    @adobe/aio-cli-plugin-runtime 3.1.0 (core)
    @oclif/plugin-autocomplete 0.3.0 (core)
    @oclif/plugin-help 2.2.3 (core)
    @oclif/plugin-not-found 1.2.4 (core)
    @oclif/plugin-plugins 1.10.0 (core)
    @oclif/plugin-warn-if-update-available 1.7.0 (core)
Done in 1.26s.

openwhisk-local.log.txt


        ____      ___                   _    _ _     _     _
       /\   \    / _ \ _ __   ___ _ __ | |  | | |__ (_)___| | __
  /\  /__\   \  | | | | '_ \ / _ \ '_ \| |  | | '_ \| / __| |/ /
 /  \____ \  /  | |_| | |_) |  __/ | | | |/\| | | | | \__ \   <
 \   \  /  \/    \___/| .__/ \___|_| |_|__/\__|_| |_|_|___/_|\_\
  \___\/ tm           |_|

Git Commit: 6feda87, Build Date: 2020-11-03T02:01:32+0800
================================================================================
Running pre flight checks ...

Local Host Name: 172.17.0.1
Local Internal Name: 172.17.0.1

[  OK   ] 'docker' cli found. (Docker version 20.10.5, build 55c4c88)
[  OK   ] 'docker' version 20.10.5 is newer than minimum supported 18.3.0
[  OK   ] 'docker' is running.
[  OK   ] 'wsk' cli found. (2021-04-01T23:49:54.523+0000)
[  OK   ] 'wsk' configured for namespace [guest].
[  OK   ] 'wsk' configured to connect to http://172.17.0.1:3233.
[  OK   ] Server port [3233] is free

================================================================================
[2021-04-29T11:07:07.530Z] [INFO] Starting OpenWhisk standalone on port 3233
[2021-04-29T11:07:07.840Z] [INFO] Slf4jLogger started
[2021-04-29T11:07:08.081Z] [INFO] Using [/home/elias/.openwhisk/standalone/server-3233] as data directory
[2021-04-29T11:07:08.478Z] [INFO] [#tid_sid_unknown] [StandaloneDockerClient] Detected docker client version 20.10.5
[2021-04-29T11:07:08.541Z] [INFO] [#tid_sid_standalone] [StandaloneDockerClient] running /usr/bin/docker ps --quiet --no-trunc --all --filter name=whisk- (timeout: 1 minute) [marker:invoker_docker.ps_start:10]
[2021-04-29T11:07:08.741Z] [INFO] [#tid_sid_standalone] [StandaloneDockerClient]  [marker:invoker_docker.ps_finish:210:107]
[2021-04-29T11:07:08.783Z] [INFO] [#tid_sid_standalone] [StandaloneDockerSupport] removing 0 containers launched for Standalone server support.
================================================================================
Launched service details

[ 3233  ] http://172.17.0.1:3233 (Controller)

Local working directory - /home/elias/.openwhisk/standalone/server-3233
================================================================================
[2021-04-29T11:07:08.953Z] [INFO] [#tid_sid_unknown] [MemoryArtifactStore] Created MemoryStore for [subjects]
[2021-04-29T11:07:08.979Z] [INFO] [#tid_sid_cli] [MemoryArtifactStore] [GET] 'subjects' finding document: 'id: guest' [marker:database_getDocument_start:108]
[2021-04-29T11:07:08.980Z] [INFO] [#tid_sid_cli] [MemoryArtifactStore]  [marker:database_getDocument_finish:109:1]
[2021-04-29T11:07:09.005Z] [INFO] [#tid_sid_cli] [MemoryArtifactStore] [PUT] 'subjects' saving document: 'id: guest, rev: null' [marker:database_saveDocument_start:134]
[2021-04-29T11:07:09.012Z] [INFO] [#tid_sid_cli] [MemoryArtifactStore]  [marker:database_saveDocument_finish:140:6]
[2021-04-29T11:07:09.013Z] [INFO] [#tid_sid_userBootstrap] [StandaloneOpenWhisk] Created user [guest]
[2021-04-29T11:07:09.051Z] [INFO] [#tid_sid_cli] [MemoryArtifactStore] [GET] 'subjects' finding document: 'id: whisk.system' [marker:database_getDocument_start:23]
[2021-04-29T11:07:09.051Z] [INFO] [#tid_sid_cli] [MemoryArtifactStore]  [marker:database_getDocument_finish:23:0]
[2021-04-29T11:07:09.055Z] [INFO] [#tid_sid_cli] [MemoryArtifactStore] [PUT] 'subjects' saving document: 'id: whisk.system, rev: null' [marker:database_saveDocument_start:27]
[2021-04-29T11:07:09.055Z] [INFO] [#tid_sid_cli] [MemoryArtifactStore]  [marker:database_saveDocument_finish:27:0]
[2021-04-29T11:07:09.055Z] [INFO] [#tid_sid_userBootstrap] [StandaloneOpenWhisk] Created user [whisk.system]
[2021-04-29T11:07:09.126Z] [WARN] Failed to attach the instrumentation because the Kamon Bundle is not present on the classpath
[2021-04-29T11:07:09.372Z] [INFO] [#tid_sid_unknown] [Config] system set value for limits.triggers.fires.perMinute
[2021-04-29T11:07:09.372Z] [INFO] [#tid_sid_unknown] [Config] system set value for limits.actions.sequence.maxLength
[2021-04-29T11:07:09.372Z] [INFO] [#tid_sid_unknown] [Config] system set value for limits.actions.invokes.concurrent
[2021-04-29T11:07:09.372Z] [INFO] [#tid_sid_unknown] [Config] system set value for whisk.api.host.name
[2021-04-29T11:07:09.372Z] [INFO] [#tid_sid_unknown] [Config] system set value for limits.actions.invokes.perMinute
[2021-04-29T11:07:09.373Z] [INFO] [#tid_sid_unknown] [Config] system set value for whisk.api.host.proto
[2021-04-29T11:07:09.373Z] [INFO] [#tid_sid_unknown] [Config] system set value for whisk.api.host.port
[2021-04-29T11:07:09.373Z] [INFO] [#tid_sid_unknown] [Config] system set value for runtimes.manifest
[2021-04-29T11:07:09.373Z] [INFO] [#tid_sid_unknown] [Config] system set value for port
[2021-04-29T11:07:09.464Z] [INFO] [#tid_sid_unknown] [LeanMessagingProvider] topic completedstandalone created
[2021-04-29T11:07:09.464Z] [INFO] [#tid_sid_unknown] [LeanMessagingProvider] topic health created
[2021-04-29T11:07:09.464Z] [INFO] [#tid_sid_unknown] [LeanMessagingProvider] topic cacheInvalidation created
[2021-04-29T11:07:09.464Z] [INFO] [#tid_sid_unknown] [LeanMessagingProvider] topic events created
[2021-04-29T11:07:09.556Z] [INFO] [#tid_sid_controller] [Controller] starting controller instance standalone [marker:controller_startup_counter:1098]
[2021-04-29T11:07:09.593Z] [INFO] [#tid_sid_unknown] [MemoryArtifactStore] Created MemoryStore for [whisks]
[2021-04-29T11:07:09.609Z] [INFO] [#tid_sid_dispatcher] [MessageFeed] handler capacity = 128, pipeline fill at = 128, pipeline depth = 256
[2021-04-29T11:07:09.631Z] [INFO] [#tid_sid_dispatcher] [MessageFeed] handler capacity = 128, pipeline fill at = 128, pipeline depth = 256
[2021-04-29T11:07:09.817Z] [INFO] [#tid_sid_unknown] [ExtendedDockerClient] Detected docker client version 20.10.5
[2021-04-29T11:07:09.817Z] [INFO] [#tid_sid_unknown] [InvokerReactive] LogStoreProvider: class org.apache.openwhisk.core.containerpool.docker.DockerCliLogStore
[2021-04-29T11:07:09.965Z] [INFO] [#tid_sid_unknown] [DockerClientWithFileAccess] Detected docker client version 20.10.5
[2021-04-29T11:07:10.104Z] [INFO] [#tid_sid_unknown] [StandaloneDockerContainerFactory] Standalone docker container factory config pullStandardImages: true
[2021-04-29T11:07:10.119Z] [INFO] [#tid_sid_invoker] [DockerClientWithFileAccess] running /usr/bin/docker ps --quiet --no-trunc --all --filter name=wsk0_ (timeout: 1 minute) [marker:invoker_docker.ps_start:1661]
[2021-04-29T11:07:10.236Z] [INFO] [#tid_sid_invoker] [DockerClientWithFileAccess]  [marker:invoker_docker.ps_finish:1777:116]
[2021-04-29T11:07:10.236Z] [INFO] [#tid_sid_invoker] [StandaloneDockerContainerFactory] removing 0 action containers.
[2021-04-29T11:07:10.330Z] [INFO] [#tid_sid_unknown] [MemoryArtifactStore] Created MemoryStore for [activations]
[2021-04-29T11:07:10.369Z] [INFO] [#tid_sid_invoker] [MemoryArtifactStore] [QUERY] 'subjects' searching 'namespaceThrottlings/blockedNamespaces [marker:database_queryView_start:1911]
[2021-04-29T11:07:10.373Z] [INFO] [#tid_sid_invoker] [MemoryArtifactStore]  [marker:database_queryView_finish:1915:4]
[2021-04-29T11:07:10.374Z] [INFO] [#tid_sid_unknown] [InvokerReactive] updated blacklist to 0 entries
[2021-04-29T11:07:10.407Z] [INFO] [#tid_sid_dispatcher] [MessageFeed] handler capacity = 40, pipeline fill at = 40, pipeline depth = 80
[2021-04-29T11:07:10.431Z] [INFO] [#tid_sid_controller] [Controller] loadbalancer initialized: LeanBalancer
[2021-04-29T11:07:10.483Z] [INFO] [#tid_sid_controller] [KindRestrictor] all kinds are allowed, the white-list is not specified
[2021-04-29T11:07:10.614Z] [INFO] [#tid_sid_unknown] [ExtendedDockerClient] Detected docker client version 20.10.5
[2021-04-29T11:07:10.949Z] [INFO] [#tid_sid_controller] [ActionsApi] actionSequenceLimit '50'
Waiting for OpenWhisk server at http://172.17.0.1:3233 to start since 834.0 μs
[2021-04-29T11:07:11.631Z] [ERROR] Bind failed for TCP channel on endpoint [/172.17.0.1:3233]
java.net.BindException: Cannot assign requested address
    at java.base/sun.nio.ch.Net.bind0(Native Method)
    at java.base/sun.nio.ch.Net.bind(Net.java:455)
    at java.base/sun.nio.ch.Net.bind(Net.java:447)
    at java.base/sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:227)
    at java.base/sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:80)
    at akka.io.TcpListener.liftedTree1$1(TcpListener.scala:59)
    at akka.io.TcpListener.<init>(TcpListener.scala:56)
    at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
    at akka.util.Reflect$.instantiate(Reflect.scala:68)
    at akka.actor.ArgsReflectConstructor.produce(IndirectActorProducer.scala:101)
    at akka.actor.Props.newActor(Props.scala:212)
    at akka.actor.ActorCell.newActor(ActorCell.scala:648)
    at akka.actor.ActorCell.create(ActorCell.scala:674)
    at akka.actor.ActorCell.invokeAll$1(ActorCell.scala:547)
    at akka.actor.ActorCell.systemInvoke(ActorCell.scala:569)
    at akka.dispatch.Mailbox.processAllSystemMessages(Mailbox.scala:293)
    at akka.dispatch.Mailbox.run(Mailbox.scala:228)
    at akka.dispatch.Mailbox.exec(Mailbox.scala:241)
    at akka.dispatch.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)
    at akka.dispatch.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)
    at akka.dispatch.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
    at akka.dispatch.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)
Waiting for OpenWhisk server at http://172.17.0.1:3233 to start since 33.39 s
[2021-04-29T11:08:12.045Z] [INFO] [#tid_sid_standalone] [StandaloneDockerClient] running /usr/bin/docker ps --quiet --no-trunc --all --filter name=whisk- (timeout: 1 minute) [marker:invoker_docker.ps_start:0]
[2021-04-29T11:08:12.155Z] [INFO] [#tid_sid_standalone] [StandaloneDockerClient]  [marker:invoker_docker.ps_finish:110:110]
[2021-04-29T11:08:12.155Z] [INFO] [#tid_sid_standalone] [StandaloneDockerSupport] removing 0 containers launched for Standalone server support.
[2021-04-29T11:08:12.156Z] [INFO] [#tid_sid_invoker] [DockerClientWithFileAccess] running /usr/bin/docker ps --quiet --no-trunc --all --filter name=wsk0_ (timeout: 1 minute) [marker:invoker_docker.ps_start:63698]
[2021-04-29T11:08:12.264Z] [INFO] [#tid_sid_invoker] [DockerClientWithFileAccess]  [marker:invoker_docker.ps_finish:63806:108]
[2021-04-29T11:08:12.264Z] [INFO] [#tid_sid_invoker] [StandaloneDockerContainerFactory] removing 0 action containers.
[2021-04-29T11:08:12.269Z] [INFO] [#tid_sid_unknown] [Controller] Shutting down Kamon with coordinated shutdown

shazron commented 3 years ago

Can you try OW_LOCAL_APIHOST=http://localhost:3233 aio app run --local to see if that makes a difference. This might be a firewall/network config issue between WSL and Windows itself, not sure.

To test maybe if this is the case, try and report the success of:

npx http-server ./ -p 3233

We haven't tried wsl2 support on Windows for a local run of Openwhisk -- we only support native Windows command line with Docker for Windows at the moment. On a native Ubuntu Linux install, it has been working as well.

eliashussary commented 3 years ago

This fails:

OW_LOCAL_APIHOST=http://localhost:3233 aio app run --local -- same error

npx http-server works no problem, there's nothing else bound to that port

➜  elias lsof -i -P -n
COMMAND    PID  USER   FD   TYPE DEVICE SIZE/OFF NODE NAME
node       950 elias   18u  IPv6  26689      0t0  TCP *:42323 (LISTEN)
node       950 elias   19u  IPv6  30932      0t0  TCP 172.30.67.240:42323->172.30.64.1:56081 (ESTABLISHED)
vsls-agen 1711 elias  204u  IPv4  20465      0t0  TCP 172.30.67.240:45778->20.42.72.4:443 (ESTABLISHED)
node      2574 elias   75u  IPv6  19969      0t0  TCP *:3000 (LISTEN)
node      4846 elias   19u  IPv6  30934      0t0  TCP 172.30.67.240:42323->172.30.64.1:56082 (ESTABLISHED)

moritzraho commented 2 years ago

We don't officially support running aio from within the WSL2 environment. However, we have worked on a workaround where the local OpenWhisk stack is run separately in a docker container using the Docker Desktop for Windows daemon (used by the docker client in WSL2) (see also https://github.com/apache/openwhisk/issues/5108#issuecomment-1277965458):

in WSL 2:

update cli: npm install -g @adobe/aio-cli
fetch the action runtimes for the local OpenWhisk stack:

mkdir ~/.openwhisk-local-runtimes/
curl https://raw.githubusercontent.com/adobe/aio-cli-plugin-app/master/bin/openwhisk-standalone-config/runtimes.json > ~/.openwhisk-local-runtime/runtimes.json

run the jar using the openwhisk-standalone wrapper script around docker (more info here), replace <your-username> below:

bash <(curl -sL https://s.apache.org/openwhisk.sh) \
-e JVM_EXTRA_ARGS=-Dwhisk.concurrency-limit.max=10 \
-v /home/<your-username>/.openwhisk-local-runtimes:/openwhisk-runtimes \
openwhisk/standalone:nightly -m /openwhisk-runtimes/runtimes.json

comment out your current apihost, namespace and auth in the .env and add a local config manually:

AIO_runtime_apihost="http://localhost:3233"
AIO_runtime_namespace="guest"
AIO_runtime_auth="23bc46b1-71f6-4ed5-8c54-816aa4f8c502:123zO3xZCLrMN6v2BKK1dXYFpXlPkccOFqm12CdAsMgRU4VrNZ9lyGVCGuMDGIwP"

now instead of aio app run --local do aio app run, this will start the local UI server and hit the local Openwhisk stack.
In Windows access https://localhost:9080 for the UI, https://localhost:3233 to hit the OpenWhisk controller/apihost and https://localhost:3232 for a local OpenWhisk debugging playground UI.

adobe / aio-cli-plugin-app

`app:run --local` fails on wsl2 environments - [ERROR] Bind failed for TCP channel on endpoint [/172.17.0.1:3232]Bind failed #401