Doesn't seem to work with Docker 1.12 (RC) swarm mode

[stefanegg]

I'm having problems getting the driver to work with the new docker swarm mode:

Environment/Preps:

• Ubuntu 16.04 LTS with latest Docker 1.12.0-rc4
• Installed and configured the driver as per documentation
• Created a local volume using
  docker volume create --name myshare -d azurefile -o share=myshare
• Volume shows up correctly using docker volume ls

A "local mode" container is working like a charm:

• Starting a new container with the volume:
  docker run -d -v myshare:/data instavote/vote
• the container starts and the volume is working perfectly

However, spinning up a container using the new Docker swarm mode does not work:

• Starting a new service with a reference to the volume:
  docker service create --name aztest --replicas 1 --mount type=volume,source=myshare,target=/data,volume-driver=azurefile instavote/vote
• no container starts
• docker service ls will always show REPLICAS 0/1
• docker ps -a will show nothing
• no specific log entries using journalctl -fu azurefile-dockervolumedriver
• no specific log entries using journalctl -fu docker
• :-(

Running the same command using a local volume works fine:

• Starting a new service with a local volume:
  docker service create --name test --replicas 1 --mount type=volume,source=myshare-local,target=/data,volume-driver=local instavote/vote

[ahmetb]

Are you running journalctl as root? There should be docker logs at least.

[stefanegg]

Sorry Ahmet, I wasn't specific enough. I DO get log entries (both for docker and azurefile-dockervolumedriver) using journalctl..., however absolutely no entries related to the docker service create --name aztest --replicas 1 --mount type=volume,source=myshare,target=/data,volume-driver=azurefile instavote/vote command. I noticed there is a debug AF_OPTS=--debug and also enabled it and restarted, but it didn't give me more.

However, I do get some entries when running the docker volume create --name myshare -d azurefile -o share=myshare command:

dockerd[2529]: time="2016-07-25T18:36:51.048564719Z" level=warning msg="Volume driver azurefile returned an error while trying to query it's capabilities, using default capabilties: VolumeDriver.Capabilities: 404 page not found\n"
dockerd[2529]: time="2016-07-25T18:36:51.232690119Z" level=warning msg="Volume driver azurefile returned an error while trying to query it's capabilities, using default capabilties: VolumeDriver.Capabilities: 404 page not found\n"
azurefile-dockervolumedriver[1700]: time="2016-07-25T18:36:51Z" level=debug msg="request accepted" name=myshare operation=get
azurefile-dockervolumedriver[1700]: time="2016-07-25T18:36:51Z" level=error msg="could not fetch metadata: cannot read metadata: open /etc/docker/plugins/azurefile/volumes/myshare: no such file or directory" name=myshare operation=get
azurefile-dockervolumedriver[1700]: time="2016-07-25T18:36:51Z" level=debug msg="request accepted" name=myshare operation=create options=map[share:myshare]
azurefile-dockervolumedriver[1700]: time="2016-07-25T18:36:51Z" level=debug msg="request accepted" name=myshare operation=path

as well as when running in "local" mode using docker run -d -v myshare:/data instavote/vote:

azurefile-dockervolumedriver[1700]: time="2016-07-25T18:40:38Z" level=debug msg="request accepted" name=myshare operation=mount

[ahmetb]

hmm could you send the full journalctl -a azurefile-dockervolumedriver logs in debug mode after restarting the service? it appears like it either lost the volume metadata it stored in /etc/docker/plugins/azurefile/volumes or something like that.

[stefanegg]

Sure, here it is:

Jul 25 19:28:56 swarm-test1-node1 systemd[1]: Stopping Azure File Service Docker Volume Driver...
Jul 25 19:28:56 swarm-test1-node1 systemd[1]: azurefile-dockervolumedriver.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Jul 25 19:28:56 swarm-test1-node1 systemd[1]: Stopped Azure File Service Docker Volume Driver.
Jul 25 19:28:56 swarm-test1-node1 systemd[1]: azurefile-dockervolumedriver.service: Unit entered failed state.
Jul 25 19:28:56 swarm-test1-node1 systemd[1]: azurefile-dockervolumedriver.service: Failed with result 'exit-code'.
Jul 25 19:28:56 swarm-test1-node1 systemd[1]: Started Azure File Service Docker Volume Driver.
Jul 25 19:28:56 swarm-test1-node1 azurefile-dockervolumedriver[4272]: time="2016-07-25T19:28:56Z" level=debug msg="Starting server." accountName=soonswarmtest1 metadata="/etc/docker/plugins/azurefile/volumes" mountpoint="/var/run/docker/volumedriver/azurefile" removeShares=false
Jul 25 19:28:56 swarm-test1-node1 azurefile-dockervolumedriver[4272]: time="2016-07-25T19:28:56Z" level=debug msg="docker group found. gid: 999"

Contents of the file /etc/docker/plugins/azurefile/volumes/myshare:

{"created_at":"2016-07-25T18:36:51.051540419Z","account":"soonswarmtest1","options":{"share":"myshare"}}

[ahmetb]

hmm I do not see the following lines, can you please run the same commands so that it fails to find the file again?

azurefile-dockervolumedriver[1700]: time="2016-07-25T18:36:51Z" level=error msg="could not fetch metadata: cannot read metadata: open /etc/docker/plugins/azurefile/volumes/myshare: no such file or directory" name=myshare operation=get
azurefile-dockervolumedriver[1700]: time="2016-07-25T18:36:51Z" level=debug msg="request accepted" name=myshare operation=create options=map[share:myshare]
azurefile-dockervolumedriver[1700]: time="2016-07-25T18:36:51Z" level=debug msg="request accepted" name=myshare operation=path

[stefanegg]

The "could not find metadata" message came from creating the volume. So I removed and re-created it:

docker volume rm myshare

Jul 25 20:04:38 swarm-test1-node1 azurefile-dockervolumedriver[4272]: time="2016-07-25T20:04:38Z" level=debug msg="request accepted" name=myshare operation=get
Jul 25 20:04:38 swarm-test1-node1 azurefile-dockervolumedriver[4272]: time="2016-07-25T20:04:38Z" level=debug msg="request accepted" name=myshare operation=remove
Jul 25 20:04:38 swarm-test1-node1 azurefile-dockervolumedriver[4272]: time="2016-07-25T20:04:38Z" level=debug msg="not removing share \"myshare\" upon volume removal" name=myshare operation=remove
Jul 25 20:04:38 swarm-test1-node1 azurefile-dockervolumedriver[4272]: time="2016-07-25T20:04:38Z" level=debug msg="removing volume metadata" name=myshare operation=remove

docker volume create --name myshare -d azurefile -o share=myshare

Jul 25 20:06:38 swarm-test1-node1 azurefile-dockervolumedriver[4272]: time="2016-07-25T20:06:38Z" level=debug msg="request accepted" name=myshare operation=get
Jul 25 20:06:38 swarm-test1-node1 azurefile-dockervolumedriver[4272]: time="2016-07-25T20:06:38Z" level=error msg="could not fetch metadata: cannot read metadata: open /etc/docker/plugins/azurefile/volumes/myshare: no such file or directory" name=myshare operation=get
Jul 25 20:06:38 swarm-test1-node1 azurefile-dockervolumedriver[4272]: time="2016-07-25T20:06:38Z" level=debug msg="request accepted" name=myshare operation=create options=map[share:myshare]
Jul 25 20:06:38 swarm-test1-node1 azurefile-dockervolumedriver[4272]: time="2016-07-25T20:06:38Z" level=debug msg="request accepted" name=myshare operation=path

Actually, I think the "could not find metadata" message is not reflecting an actual error. Maybe it just checks for the volume existence before creating it. The weird thing is that there are zero log entries when running the service create command. I might check with the docker guys to see if we can get more insight.

[ahmetb]

@stefanegg ah right, it's for the /Volumes.Get operation and is checking if volume exists by examining its metadata path. Can you perhaps try another Docker Volume driver (https://docs.docker.com/engine/extend/plugins_volume/) and see if they are compatible with Docker-1.12.

Until now, as volume driver authors we have been broken at every single Docker release since volume drivers came out. So I wouldn't be surprised the swarm mode is somewhat incompatible or does things different than before.

[stefanegg]

@ahmetalpbalkan, looks like the latest release(s) fixed this. I can confirm it works successfully with the latest final Docker release (1.12.0) and the latest version of the azurefile-dockervolumedriver (0.4.1) on an Ubuntu 16.04 LTS Azure VM.
Thanks for looking into it!