Error in Docker Managed IPAM Plugin

[ishantt]

I have created a sample docker IPAM plugin to test the plugin interface. https://github.com/ishantt/docker-ipam-plugin .This works fine if I run in legacy mode i.e. spawning a external container. But If a create a Docker Managed plugin (v2 plugin) then it gives error .
dial unix /run/docker/plugins/sdip.sock: connect: no such file or directory

$ docker plugin enable ishant8/sdip

$ tailf /var/log/syslog

May 21 23:10:01 omega dockerd[1993]: time="2017-05-21T23:10:01+05:30" level=info msg="time=\"2017-05-21T17:40:01Z\" level=info msg=\"Starting Docker IPAM Plugin\" " plugin=408bdafe68205f22c98b432901952408d9aa6f31be668b9f59e0252843b72174
May 21 23:10:01 omega dockerd[1993]: time="2017-05-21T23:10:01+05:30" level=info msg="time=\"2017-05-21T17:40:01Z\" level=info msg=\"Listening on socket /run/docker/plugins/sdip.sock\" " plugin=408bdafe68205f22c98b432901952408d9aa6f31be668b9f59e0252843b72174
May 21 23:10:01 omega dockerd[1993]: time="2017-05-21T23:10:01+05:30" level=info msg="time=\"2017-05-21T17:40:01Z\" level=info msg=\"GetCapabilities called\" " plugin=408bdafe68205f22c98b432901952408d9aa6f31be668b9f59e0252843b72174
May 21 23:10:01 omega dockerd[1993]: time="2017-05-21T23:10:01+05:30" level=info msg="time=\"2017-05-21T17:40:01Z\" level=info msg=\"GetDefaultAddressSpaces called\" " plugin=408bdafe68205f22c98b432901952408d9aa6f31be668b9f59e0252843b72174
May 21 23:10:01 omega dockerd[1993]: time="2017-05-21T23:10:01+05:30" level=info msg="time=\"2017-05-21T17:40:01Z\" level=info msg=\"Returing response LocalDefaultAddressSpace: LOCAL, GlobalDefaultAddressSpace: GLOBAL\" " plugin=408bdafe68205f22c98b432901952408d9aa6f31be668b9f59e0252843b72174

$ docker network create --ipam-driver sdip net2
Error response from daemon: Post http://%2Frun%2Fdocker%2Fplugins%2Fsdip.sock/IpamDriver.RequestPool: dial unix /run/docker/plugins/sdip.sock: connect: no such file or directory

May 21 23:25:42 omega dockerd[1993]: time="2017-05-21T23:25:42.206679177+05:30" level=warning msg="Unable to connect to plugin: /run/docker/plugins/sdip.sock/IpamDriver.RequestPool: Post http://%2Frun%2Fdocker%2Fplugins%2Fsdip.sock/IpamDriver.RequestPool: dial unix /run/docker/plugins/sdip.sock: connect: no such file or directory, retrying in 1s"
May 21 23:25:43 omega dockerd[1993]: time="2017-05-21T23:25:43.208054113+05:30" level=warning msg="Unable to connect to plugin: /run/docker/plugins/sdip.sock/IpamDriver.RequestPool: Post http://%2Frun%2Fdocker%2Fplugins%2Fsdip.sock/IpamDriver.RequestPool: dial unix /run/docker/plugins/sdip.sock: connect: no such file or directory, retrying in 2s"
May 21 23:25:45 omega dockerd[1993]: time="2017-05-21T23:25:45.209120344+05:30" level=warning msg="Unable to connect to plugin: /run/docker/plugins/sdip.sock/IpamDriver.RequestPool: Post http://%2Frun%2Fdocker%2Fplugins%2Fsdip.sock/IpamDriver.RequestPool: dial unix /run/docker/plugins/sdip.sock: connect: no such file or directory, retrying in 4s"
May 21 23:25:49 omega dockerd[1993]: time="2017-05-21T23:25:49.210663653+05:30" level=warning msg="Unable to connect to plugin: /run/docker/plugins/sdip.sock/IpamDriver.RequestPool: Post http://%2Frun%2Fdocker%2Fplugins%2Fsdip.sock/IpamDriver.RequestPool: dial unix /run/docker/plugins/sdip.sock: connect: no such file or directory, retrying in 8s"
May 21 23:25:57 omega dockerd[1993]: time="2017-05-21T23:25:57.212136134+05:30" level=error msg="Handler for POST /v1.27/networks/create returned error: Post http://%2Frun%2Fdocker%2Fplugins%2Fsdip.sock/IpamDriver.RequestPool: dial unix /run/docker/plugins/sdip.sock: connect: no such file or directory"

On docker Host

$ docker plugin ls
ID                  NAME                  DESCRIPTION                     ENABLED
f958844bc68c        ishant8/sdip:latest   Sample IPAM plugin for Docker   true
$ ls -l /run/docker/plugins
total 0
drwx------ 2 root root 60 May 21 23:19 f958844bc68ca9eddea8b064977e1c9da644c597d4f2b46344431c1d97bfbfaf
$ ls -l /run/docker/plugins/f958844bc68ca9eddea8b064977e1c9da644c597d4f2b46344431c1d97bfbfaf
total 0
srw-rw---- 1 root root 0 May 21 23:19 sdip.sock

Steps to reproduce:

1. git clone http://github.com/ishantt/docker-ipam-plugin
2. cd docker-ipam-plugin
3. make all
4. docker network create --ipam-driver sdip net1

Docker Version:

$ docker version
Client:
 Version:      17.03.1-ce
 API version:  1.27
 Go version:   go1.7.5
 Git commit:   c6d412e
 Built:        Mon Mar 27 17:14:09 2017
 OS/Arch:      linux/amd64

Server:
 Version:      17.03.1-ce
 API version:  1.27 (minimum version 1.12)
 Go version:   go1.7.5
 Git commit:   c6d412e
 Built:        Mon Mar 27 17:14:09 2017
 OS/Arch:      linux/amd64
 Experimental: false

docker info:

$ docker info
Containers: 10
 Running: 0
 Paused: 0
 Stopped: 10
Images: 7
Server Version: 17.03.1-ce
Storage Driver: aufs
 Root Dir: /var/lib/docker/aufs
 Backing Filesystem: extfs
 Dirs: 30
 Dirperm1 Supported: true
Logging Driver: json-file
Cgroup Driver: cgroupfs
Plugins:
 Volume: local
 Network: bridge host macvlan null overlay
Swarm: inactive
Runtimes: runc
Default Runtime: runc
Init Binary: docker-init
containerd version: 4ab9917febca54791c5f071a9d1f404867857fcc
runc version: 54296cf40ad8143b62dbcaa1d90e520a2136ddfe
init version: 949e6fa
Security Options:
 apparmor
 seccomp
  Profile: default
Kernel Version: 4.4.0-62-generic
Operating System: Ubuntu 16.04.2 LTS
OSType: linux
Architecture: x86_64
CPUs: 1
Total Memory: 4.712 GiB
Name: omega
ID: 6PMZ:P2FI:KOYB:2AS3:6NWN:YG5L:ZXUZ:YIJR:6DWX:VRVG:W4QD:6V7D
Docker Root Dir: /var/lib/docker
Debug Mode (client): false
Debug Mode (server): false
Registry: https://index.docker.io/v1/
WARNING: No swap limit support
Experimental: false
Insecure Registries:
 127.0.0.0/8
Live Restore Enabled: false

[ishantt]

After Restarting the docker engine and creating network again

$ docker network create --ipam-driver sdip net2
Error response from daemon: legacy plugin: plugin not found

$ tailf /var/log/syslog
May 22 08:50:11 omega dockerd[18099]: time="2017-05-22T08:50:11.658751241+05:30" level=warning msg="Unable to locate plugin: sdip, retrying in 1s"
May 22 08:50:12 omega dockerd[18099]: time="2017-05-22T08:50:12.659499230+05:30" level=warning msg="Unable to locate plugin: sdip, retrying in 2s"
May 22 08:50:14 omega dockerd[18099]: time="2017-05-22T08:50:14.662269520+05:30" level=warning msg="Unable to locate plugin: sdip, retrying in 4s"
May 22 08:50:18 omega dockerd[18099]: time="2017-05-22T08:50:18.664706981+05:30" level=warning msg="Unable to locate plugin: sdip, retrying in 8s"
May 22 08:50:26 omega dockerd[18099]: time="2017-05-22T08:50:26.666627444+05:30" level=error msg="Handler for POST /v1.27/networks/create returned error: legacy plugin: plugin not found"

[ishantt]

Looks like issue is with the code here
https://github.com/moby/moby/blob/master/pkg/plugins/discovery.go#L62
socketpaths := pluginPaths(socketsPath, name, ".sock")

func pluginPaths(base, name, ext string) []string {
	return []string{
		filepath.Join(base, name+ext),
		filepath.Join(base, name, name+ext), <---**This returns name instead of ID** 
	}
}

socketpaths list has two paths for the socket 1) /run/docker/plugins/sdip.sock 2) /run/docker/plugins/sdip/sdip.sock
But the socket is created in the path /run/docker/plugins/< container id >/sdip.sock

$ ls -l /run/docker/plugins/f958844bc68ca9eddea8b064977e1c9da644c597d4f2b46344431c1d97bfbfaf
total 0
srw-rw---- 1 root root 0 May 21 23:19 sdip.sock

[ishantt]

Looks like issue in Moby. Raised the same issue in moby/moby#33347

[eyz]

@ishantt I think we determined the solution for this in Docker Community slack a couple days ago. I've been able to use your plugin fine, and I think the issue was not specifying the full "ishant8/sdip:latest" in the --ipam-driver. Can this be closed?

[ishantt]

@eyz yes using full name "ishant8/sdip:latest" worked. I was again and again trying to create with the name "ishant8/sdip" as given in docs ( https://docs.docker.com/engine/extend/#installing-and-using-a-plugin ) and it was failing. Maybe this needs a doc change.

Anyways I am happy to close this .