Desktop 3.0.0: listen tcp: bind: An attempt was made to access a socket in a way forbidden by its access permissions.

[rfay]

• I have tried with the latest version of my channel (Stable or Edge)
• I have uploaded Diagnostics: Unfortunately, this happens in a CI environment and I haven't yet been able to capture diagnostics right after it happens
• Diagnostics ID:

Expected behavior

No port complaints

Actual behavior

With Docker Desktop 3.0.0 and WSL2 back-end, I'm seeing intermittent but regular failures on start of a container "listen tcp 127.0.0.1:49383: bind: An attempt was made to access a socket in a way forbidden by its access permissions."

This seems to have started with Docker Desktop 3.0.0, but it's now becoming very consistent.

An example is https://github.com/drud/ddev/pull/2615/checks?check_run_id=1648025859

Recreating ddev-TestCmdWordpress-db ... error
ERROR: for ddev-TestCmdWordpress-db  Cannot start service db: Ports are not available: listen tcp 127.0.0.1:49383: bind: An attempt was made to access a socket in a way forbidden by its access permissions.
ERROR: for db  Cannot start service db: Ports are not available: listen tcp 127.0.0.1:49383: bind: An attempt was made to access a socket in a way forbidden by its access permissions.

The port that it complains about is not consistent (here it's 49383, in another example it's 49720. When you go check the port, there's nothing listening on it.

The context here is a database container being brought up by docker-compose; it has this stanza:

    ports:
    - 127.0.0.1::3306/tcp

So perhaps this has something to do with the 3-part ports statement?

I've tried factory reset. I've tried disabling Hyper-V.

[stephen-turner]

The three-part ports statement is broken at the moment. This is #4541, but I'm not aware that it's become worse recently.

[rfay]

@stephen-turner thanks for the reply - 4541 doesn't look like the issue though. And we've been using the 3-part port statement for a couple of years... And it works most of the time.

[stephen-turner]

Ah yes, sorry, it was docker/for-mac#4541.

We've had another report in the last week (docker/for-mac#5205) so I guess it has got worse recently in some way. We'll have a look.

[rfay]

Thanks @stephen-turner - I'm not at all sure this is the same issue as described over there. What's happening here is that we're doing a 3-part ports but using 127.0.0.1. It almost always works fine (and no trouble on macOS or Linux), but randomly fails on Windows and the ephemeral port chosen to be exposed fails with the "An attempt was made to access a socket in a way forbidden by its access permissions". I may be wrong, but I think this is new in 3.0.0 on Windows.

[stephen-turner]

Oh, no trouble on Mac either? I agree, that would suggest it's a different issue.

[rfay]

I was unable to get any successful DDEV test runs with Docker Desktop for Windows 3.0.0 because of this issue, so I had to go through all the Windows test runners, uninstall 3.0.0 and install Docker Desktop for Windows 2.5.0.1. Now have run several PRs through several test runs and have not seen this issue at all. This is sad, because ddev really tries to be docker-version agnostic, supporting Docker 18.06 and higher, which is a broad range.

[rfay]

Similar behavior seems to be reported in Docker 3.1.0 on macOS as well.

[stephen-turner]

Yes, nothing has changed for this in 3.1.0. We're working on it at the moment: @simonferquel will have a test build soon.

[rfay]

@stephen-turner is it reasonable to believe that the same problem exists in 3.x on both Windows and macOS? (Slightly different complaint, but seems to be the same thing)

[simonferquel]

Hi @rfay I am working on this. The main issue we have, is that port exposition is done in a very different manner on Desktop than on native-Linux: On native Linux, the Docker engine handles the whole networking. On Desktop, part of the networking is done by Docker Engine, and another part is done by the Desktop network system.

As an example, imagine on your host machine you have a local network IP such as 10.0.1.42. You want to expose to other people on your network a service using Docker: you would issue something like docker run -p 10.0.1.42:80:80 .... The VM within which the docker engine runs don't have an interface with this IP address. So Docker Desktop intercept the API calls and transforms it to ask docker for -p 127.0.0.1::80 and it setup the relay between the requested host endpoint 10.0.1.42:80 and the port allocated within the VM.

The problem here is that now, when you "inspect" the container (which is what compose does), you get the IP/port allocated in the VM, not what has been setup on the host. I am currently fixing exactly this bug, which I think should solve the issue.

[simonferquel]

And yes, the same code runs on both of Windows and MacOS with the same container config rewriting issue.

[rfay]

Thanks @simonferquel !

[stephen-turner]

Ah, sorry @rfay, now I see what you were saying -- you were saying that it was also on MacOS, not that it was still in 3.1.0. I hadn't remembered that this was a for-win bug as you're more often in for-mac!

[rfay]

One thing to be clear about @simonferquel - The behavior we've seen on both Windows and macOS is intermittent, and can be resolved by stopping all containers, or perhaps by restarting docker. It works most of the time.

[simonferquel]

Hi @rfay here is a preview build fixing the issue: https://desktop.docker.com/win/preview/60183/Docker%20Desktop%20Installer.exe (mac one is currently building).
This introduces 2 changes:

• dynamic ports allocation should not fail anymore (previously we used the same port on the host as the one allocated within the VM, we changed that).
• docker ps and docker inspect should now show the IP:port allocated on the host instead of the ones allocated within the VM.

[simonferquel]

And here is the mac build: https://desktop.docker.com/mac/preview/60183/Docker.dmg. Please let me know if it works better for you

[rfay]

Thanks for your work on these @simonferquel - What is the auto-update behavior of preview builds like this? The only place I've seen this predictably (but intermittently) is on our Windows test runners, so trying out the preview means a lot of installation and then watching the behavior.

[simonferquel]

Hmm this preview is disconnected from our main update stream. We can setup a redirection to the main stream once the patch makes it to a normal build though.
Is there an isolated machine on which you can test it without having to change your whole test environment ?

[rfay]

It's good that it's disconnected, thanks.

The problem is that I seem to only see this (intermittently but often) when running the full test suite on Windows.

[rfay]

Doing some casual testing @simonferquel I see a bunch of what appears to be debug output that was unexpected:

Building web                                                                                                                  
#1 [internal] load build definition from Dockerfile                                                                           
#1 sha256:7afe3b9f77056abf3302dbe3e7d0d26ca72e86710697bb812c9fcb863337cd7b                                                    
#1 transferring dockerfile: 338B done                                                                                         
#1 DONE 0.1s                                                                                                                  
                                                                                                                              
#2 [internal] load .dockerignore                                                                                              
#2 sha256:61c01dec6233a288feb8ad1c3272b70db8df3e6d923bd1c3a2d1ed3749d3db03                                                    
#2 transferring context: 2B done                                                                                              
#2 DONE 0.1s                                                                                                                  
                                                                                                                              
#3 [internal] load metadata for docker.io/drud/ddev-webserver:20210111_lolautruche_blackfire                                  
#3 sha256:cc140c4baf3ae8a54ef1050778c517e11ebba8de16fe36de10ba5512856dc168                                                    
#3 DONE 0.0s                                                                                                                  
                                                                                                                              
#5 [1/2] FROM docker.io/drud/ddev-webserver:20210111_lolautruche_blackfire                                                    
#5 sha256:265f6d1bbeef9a32d235ada3bde55604e6020fca787921ec079b46bd5f7ecf2e                                                    
#5 resolve docker.io/drud/ddev-webserver:20210111_lolautruche_blackfire done                                                  
#5 DONE 0.0s                                                                                                                  
                                                                                                                              
#4 [2/2] RUN (groupadd --gid 1000 "rfay" || groupadd "rfay" || true) && (useradd  -l -m -s "/bin/bash" --gid "rfay" --comment 
' --uid 1000 "rfay" || useradd  -l -m -s "/bin/bash" --gid "rfay" --comment '' "rfay")                                        
#4 sha256:2cdae4d0d16f6a0bc5a97f1a94cee2aee1165c67f287af8ca54158b3277515f2                                                    
#4 DONE 0.6s                                                                                                                  
                                                                                                                              
#6 exporting to image                                                                                                         
#6 sha256:e8c613e07b0b7ff33893b694f7759a10d42e180f2b4dc349fb57dc6b71dcab00                                                    
#6 exporting layers 0.1s done                                                                                                 
#6 writing image sha256:4dedc84409f1e512ccb30d717afd536c9c218c832f7fb8394cc3a9158a913b59 done                                 
#6 naming to docker.io/drud/ddev-webserver:20210111_lolautruche_blackfire-d8-built done                                       
#6 DONE 0.1s                                                                                                                  
Creating ddev-d8-db ... done                                                                                                  
Creating ddev-d8-web ... done                                                                                                 
Creating ddev-d8-dba ... done                                                                                                 
                                                                                                                              
Building with native build. Learn about native build in Compose here: https://docs.docker.com/go/compose-native-build/        
Creating ddev-router ... done                                                                                                 
                                                                                                                              
Ensuring write permissions for d8                                                                                             
Ensuring write permissions for d8                                                                                             
Existing settings.php file includes settings.ddev.php                                                                         
Successfully started d8                                                                                                       
Project can be reached at https://d8.ddev.site https://127.0.0.1:59918                                                        
rfay@rfay-win10pro ~/workspace/d8                                                                                             
λ                                                                                                                             ```

[simonferquel]

what is unexpected here ?

[rfay]

#1 [internal] load build definition from Dockerfile                                                                           
#1 sha256:7afe3b9f77056abf3302dbe3e7d0d26ca72e86710697bb812c9fcb863337cd7b                                                    
#1 transferring dockerfile: 338B done                                                                                         
#1 DONE 0.1s                                                                                                                  

Edit: Maybe a change with buildkit? I haven't seen this kind of output on a simple start before.

[simonferquel]

This might be because the version of compose on this build defaults to using buildkit for building containers. Previously it used the legacy builder. I think ddev start implies running docker compose build under the hood.

[rfay]

It looks like buildkit output. Is the change to buildkit related to this bug?

[simonferquel]

no, it is just that it is based on our main branch, which has other changes compared to the public build.

[rfay]

Thanks. I haven't seen that output in any Linux version of docker-compose at this point, so will need to figure out how to quiet it. Do you know what version of docker-compose it's introduced in?

This build seems to break lots and lots of ddev tests, partly because of changed output from docker-compose, but there also seem to be files not being released by previous usages. We've had this problem before with Docker-for-win, see #6512 and #5530 (comment).

[rfay]

Interesting on this machine I'm testing on. docker-compose on Windows is v1.28.0-rc3, but in WSL2 it's 1.27.4. This happens even if I restart the WSL2 instance and restart docker.

[simonferquel]

Hmm interesting. I'll have a look at the compose version mismatch. For the file locks, I'll invoke @djs55 :D

[rfay]

I was able to get a full test run to go through with just one change to a fragile test. The docker-compose output change broke that one. After the PR for that one goes in I'll consider putting this on the test runners.

Manual testing of a few DDEV-Local activities was successful, except for how amazingly slow everything on Windows once you get used to WSL2 or even macOS with NFS.

The new docker-compose build is way too chatty; the output "Building with native build. Learn about native build in Compose here: https://docs.docker.com/go/compose-native-build/" and then all the new buildkit chatter are certainly unwanted in the context of a ddev start. It looks like the big change in docker-compose 1.28 is that COMPOSE_DOCKER_CLI_BUILD=1 by default. So (and I tested) I can just use export COMPOSE_DOCKER_CLI_BUILD=0. But it would probably be kind of you to add this as an experimental feature off by default in the next release instead of surprising everybody so much.

I'd be interested to know if there's a way to control that better. BUILDKIT_PROGRESS doesn't help. You can just get "plain" or "auto", but I'd just like to not see it (except failures).

[simonferquel]

We are not sure yet compose 1.28 will make it to the final build (we found a few regressions on our side), so if you confirm that setting COMPOSE_DOCKER_CLI_BUILD=0 makes it work as before, I think we are happy.

Compose 1.28 and the move to buildkit is inevitable at some point though, and I think ddev should be updated to work well with it (essentially, because buildkit is much faster in most cases, and provides a lot of new interesting features - build cache, ssh mounts, better multi-arch/platform support etc.)

[rfay]

Good news: I installed #10008 (comment) on all the ddev Windows test-runners yesterday and ran many hours of many PRs against it and never saw the issue reported here. Thanks so much for you work on this!

I have an experimental PR with COMPOSE_DOCKER_CLI_BUILD=0 which should do no harm. Eventually I guess I'll have to capture all docker-compose output anyway. I'm not quite as much a fan of buildkit as you are. I use it and am glad it exists for multi-arch builds, but beyond that it's really, really hard to debug and output really hard to understand and manage, and I haven't seen the speed advantage. But of course, as soon as I started using it I was doing multi-arch builds, which are oh-so-slow.

[rfay]

I did see this today on the 60183 build on a test runner, but it's the first time in a while. I think that can also be caused by various other random things, including ports actually being listened to by another process.

ERROR: for ddev-specapp-db  Cannot start service db: Ports are not available: listen tcp 127.0.0.1:64288: bind: An attempt was made to access a socket in a way forbidden by its access permissions.
  |  
  | ERROR: for db  Cannot start service db: Ports are not available: listen tcp 127.0.0.1:64288: bind: An attempt was made to access a socket in a way forbidden by its access permissions.
 ```

[davidathompson]

I think what was done in 3.2.0 broke a use case one windows containers. Run:

docker run -it --rm -p 80 --name aspnetcore_sample mcr.microsoft.com/dotnet/samples:aspnetapp

It should auto assign the port. The error is now displaying:

docker: Error response from daemon: failed to create endpoint aspnetcore_sample on network nat: Windows does not support host IP addresses in NAT settings.

[stephen-turner]

This bug was fixed in version 3.2.0, so I'll close this ticket now.

I see @davidathompson has opened the last comment as a separate bug at #10552, so we'll take that there.

[rfay]

Well, I think it's better in 3.2.0, but I still see it periodically, and see it in quite a lot now in macOS 3.2.0 as well.

[johnkwaters]

I just updated to 3.2.2 and now I get this

ERROR: for MetaDataApi Cannot start service metadataapi: failed to create endpoint MetaDataApi on network dockercompose8027615097735105285_default: Windows does not support host IP addresses in NAT settings
Creating IdentityServer ... error
ERROR: for IdentityServer Cannot start service identityserver: failed to create endpoint IdentityServer on network dockercompose8027615097735105285_default: Windows does not support host IP addresses in NAT settings

I didn't change anything in my docker-compose.yml - it was the Docker Desktop update that broke something. What to do?

[stephen-turner]

@johnkwaters That is a different bug, and is tracked at #10552.

[snaeqe]

Ran into the same issue with 3.2.2 using the Hyper-V Backend:

$ docker-compose up
Starting mosquitto_mosquitto_1 ...
Starting mosquitto_mosquitto_1 ... error

ERROR: for mosquitto_mosquitto_1 Cannot start service mosquitto: Ports are not available: listen tcp 0.0.0.0:1883: bind: An attempt was made to access a socket in a way forbidden by its access permissions.

ERROR: for mosquitto Cannot start service mosquitto: Ports are not available: listen tcp 0.0.0.0:1883: bind: An attempt was made to access a socket in a way forbidden by its access permissions.
Encountered errors while bringing up the project.

Compose-file:

$ cat docker-compose.yaml
version: "3.3"
services:
mosquitto:
image: eclipse-mosquitto
ports:
- 1883:1883
- 9001:9001
volumes:
- ./config:/mosquitto/config`

[snaeqe]

Interestingly enough, if I change the Compose-file, it works:

$ cat docker-compose.yaml
version: "3.3"
services:
mosquitto:
image: eclipse-mosquitto
ports:

• 1883
• 9001
  volumes:
• ./config:/mosquitto/config

$ docker-compose up
Starting mosquitto_mosquitto_1 ...
Starting mosquitto_mosquitto_1 ... done
Attaching to mosquitto_mosquitto_1
mosquitto_1 | 1617093130: mosquitto version 2.0.9 starting
mosquitto_1 | 1617093130: Config loaded from /mosquitto/config/mosquitto.conf.
mosquitto_1 | 1617093130: Starting in local only mode. Connections will only be possible from clients running on this machine.
mosquitto_1 | 1617093130: Create a configuration file which defines a listener to allow remote access.
mosquitto_1 | 1617093130: Opening ipv4 listen socket on port 1883.
mosquitto_1 | 1617093130: Opening ipv6 listen socket on port 1883.
mosquitto_1 | 1617093130: Error: Address not available
mosquitto_1 | 1617093130: mosquitto version 2.0.9 running

[snaeqe]

Reverting the change brings up the error again

[rfay]

@snaeqe the two things you did are not equivalent. Just setting

ports
- 1833

allows binding on the host with an ephemeral, or random port. It's not force-binding a particular port. Using "1833:1833" forces it to bind on the host on 1833.

So this explains why you have a different result.

[snaeqe]

Well, thanks for pointing this out..

stares at a spot on his desktop that seems suitable to plant a face there

I'm not questioning the technical accuracy of this, but can anybody help me understand the reasoning behind this behaviour? This is.. slightly counterintuitive to me. My understanding was that using just the container port would try to map this to the host 1:1 and fail if impossible, while the portmap a:b gives you the ability to access multiple apps running on the same container port in differend containers, with the common a:a being a "best-practice" to for documentation/examples to ease future parallel operations..

[stephen-turner]

@snaeqe This dates from the very earliest days of Docker, but the idea is that it's useful to be able to bind to a random available port. I suppose one could have invented another syntax for that and then made -p 80 a shorthand for -p 80:80, but they didn't.

[basseye]

ERROR: for ddev-router Cannot start service ddev-router: Ports are not available: listen tcp 127.0.0.1:80: bind: An attempt was made to access a socket in a way forbidden by its access permissions.

I've had this problem for a few weeks on with wsl2 on Windows 10. Obviously, going by this thread nothing has changed and this problem persist. Or I'm missing something?

[ValCat94]

I've just had the same issue, for me helped this https://stackoverflow.com/a/59044246/15785558

[docker-robott]

Closed issues are locked after 30 days of inactivity.
This helps our team focus on active issues.

If you have found a problem that seems similar to this, please open a new issue.

Send feedback to Docker Community Slack channels #docker-for-mac or #docker-for-windows.
/lifecycle locked