trident icon indicating copy to clipboard operation
trident copied to clipboard
verified publisher icon NetApp

trident with dockerd configured with --data-root

Open olivpass opened this issue 4 years ago • 8 comments

Describe the bug trident Version 21.01.1 does not work, if dockerd is configured with option --data-root

Environment Provide accurate information about the environment to help us reproduce the issue.

  • Trident version: 21.01.1
  • Trident installation flags used: docker plugin install --grant-all-permissions --alias aff3hosts netapp/trident-plugin:21.01.1 config=aff3hosts-config.json
  • Container runtime: Docker version 19.03.15
  • OS: openSUSE Leap 15.2
  • NetApp backend types: ONTAP AFF 9.7

To Reproduce dockerd is running with following command line Option --data-root:

/usr/bin/dockerd --add-runtime oci=/usr/sbin/docker-runc --data-root /icvar/var_lib_docker

ollitestd:~ # cat /etc/netappdvp/aff3hosts-config.json 
{
    "version": 1,
    "storageDriverName": "ontap-nas",
    "managementLIF": "172.x.y.z1",
    "dataLIF": "172.x.y.z2",
    "svm": "docker",
    "storagePrefix": "ollitestd_",
    "username": "trident_user",
    "password": "xxx",
    "aggregate": "AFF3N1_data01",
    "nfsMountOptions": "-o nfsvers=4",
    "defaults": {
      "size": "2G",
      "spaceReserve": "none",
      "exportPolicy": "hosts"
    }
}
docker plugin install --grant-all-permissions --alias aff3hosts netapp/trident-plugin:21.01.1 config=aff3hosts-config.json
docker volume create --driver aff3hosts test
docker run -it --rm -v test:/data alpine /bin/sh
docker: Error response from daemon: OCI runtime create failed: container_linux.go:349: starting container process caused "process_linux.go:449: container init caused \"rootfs_linux.go:58: mounting \\\"/icvar/var_lib_docker/plugins/452d6e670873343c2b8c247986c9203630b3043629818589c508a3a76f031c8b/propagated-mount/ollitestd_test\\\" to rootfs \\\"/icvar/var_lib_docker/overlay2/0d32e5dde882bcbc22f2284cb4b2c00412570335098ddf64c9598a83d097e6db/merged\\\" at \\\"/data\\\" caused \\\"stat /icvar/var_lib_docker/plugins/452d6e670873343c2b8c247986c9203630b3043629818589c508a3a76f031c8b/propagated-mount/ollitestd_test: no such file or directory\\\"\"": unknown.

ollitestd:~ # mount | grep olli
172.x.y.z2:/ollitestd_test on /var_lib_docker/plugins/452d6e670873343c2b8c247986c9203630b3043629818589c508a3a76f031c8b/propagated-mount/ollitestd_test type nfs4 (rw,relatime,vers=4.0

you see a missing prefix /icvar on the propagated-mount!

without dockerd option --data-root my setup is working!

olivpass avatar Mar 16 '21 11:03 olivpass

OK, i have one more relevant Information. If i start docker as the same way but the top folder /test is on the same filesystem. This is different of the filesystem /icvar:

ollitestd:~ # df -PTh /test
Filesystem     Type  Size  Used Avail Use% Mounted on
/dev/sda3      xfs    20G  1.4G   19G   7% /
ollitestd:~ # df -PTh /icvar
Filesystem     Type  Size  Used Avail Use% Mounted on
/dev/sdb1      ext4   20G  119M   19G   1% /icvar

/usr/bin/dockerd --add-runtime oci=/usr/sbin/docker-runc --data-root /test/var_lib_docker

data-root with /test/var_lib_docker is working! data-root with /icvar/var_lib_docker on different filesysten is not working!

olivpass avatar Mar 17 '21 08:03 olivpass

Hi @olivpass,

I checked with the team and the data-root option is not something that Docker passes to the Trident Docker Plugin. This may be a docker bug.

gnarl avatar Mar 18 '21 14:03 gnarl

Hi @gnarl,

i think not, because the older trident 20.01 I actual normally use, is working with the described setup. And yes, this is also a relevant information. Excuse me!

olivpass avatar Mar 18 '21 15:03 olivpass

Hi @gnarl,

next check, upgrade docker to version 20.10.5-ce. Same:

user@ollitestd:~> docker run -it --rm -v test:/data alpine /bin/sh 
docker: Error response from daemon: OCI runtime create failed: container_linux.go:367: starting container process caused: process_linux.go:495: container init caused: rootfs_linux.go:60: mounting "/icvar/var_lib_docker/plugins/fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d/propagated-mount/ollitestd_test" to rootfs at "/data" caused: stat /icvar/var_lib_docker/plugins/fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d/propagated-mount/ollitestd_test: no such file or directory: unknown.
ERRO[0000] error waiting for container: context canceled 

ollitestd:/ # mount | grep nfs
172.x.y.z1:/ollitestd_test on /var_lib_docker/plugins/fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d/propagated-mount/ollitestd_test type nfs4 (rw,relatime,vers=4.0,rsize=65536,wsize=65536,namlen=255,hard,proto=tcp,timeo=600,retrans=2,sec=sys,clientaddr=172.x.y.z2,local_lock=none,addr=172.x.y.z1)

Mar 18 16:46:04 ollitestd dockerd[1510]: time="2021-03-18T16:46:04+01:00" level=error msg="2021/03/18 15:46:04 Entering go-plugins-helpers listPath" plugin=fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d
Mar 18 16:46:04 ollitestd dockerd[1510]: time="2021-03-18T16:46:04+01:00" level=info msg="time=\"2021-03-18T15:46:04Z\" level=info msg=\"Added 1 existing volume(s)\" requestID=6376f9ed-bfa1-4237-8fbd-6fe5360f7779 requestSource=Docker" plugin=fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d
Mar 18 16:46:04 ollitestd dockerd[1510]: time="2021-03-18T16:46:04+01:00" level=error msg="2021/03/18 15:46:04 Entering go-plugins-helpers capabilitiesPath" plugin=fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d
Mar 18 16:46:17 ollitestd dockerd[1510]: time="2021-03-18T16:46:17+01:00" level=error msg="2021/03/18 15:46:17 Entering go-plugins-helpers listPath" plugin=fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d
Mar 18 16:46:17 ollitestd dockerd[1510]: time="2021-03-18T16:46:17+01:00" level=info msg="time=\"2021-03-18T15:46:17Z\" level=info msg=\"Added 1 existing volume(s)\" requestID=0160147f-b9de-4214-861d-7b383f747d06 requestSource=Docker" plugin=fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d
Mar 18 16:46:17 ollitestd dockerd[1510]: time="2021-03-18T16:46:17+01:00" level=error msg="2021/03/18 15:46:17 Entering go-plugins-helpers capabilitiesPath" plugin=fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d
Mar 18 16:46:35 ollitestd dockerd[1510]: time="2021-03-18T16:46:35+01:00" level=error msg="2021/03/18 15:46:35 Entering go-plugins-helpers capabilitiesPath" plugin=fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d
Mar 18 16:46:35 ollitestd dockerd[1510]: time="2021-03-18T16:46:35+01:00" level=error msg="2021/03/18 15:46:35 Entering go-plugins-helpers getPath" plugin=fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d
Mar 18 16:46:35 ollitestd dockerd[1510]: time="2021-03-18T16:46:35+01:00" level=info msg="time=\"2021-03-18T15:46:35Z\" level=info msg=\"Added 1 existing volume(s)\" requestID=3fbb7182-c7a1-4a8b-83a7-deffccc0eaab requestSource=Docker" plugin=fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d
Mar 18 16:46:35 ollitestd dockerd[1510]: time="2021-03-18T16:46:35+01:00" level=error msg="2021/03/18 15:46:35 Entering go-plugins-helpers capabilitiesPath" plugin=fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d
Mar 18 16:46:35 ollitestd systemd-udevd[2177]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Mar 18 16:46:35 ollitestd systemd-udevd[2177]: Could not generate persistent MAC address for veth29e5ecd: No such file or directory
Mar 18 16:46:35 ollitestd systemd-udevd[2176]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Mar 18 16:46:35 ollitestd systemd-udevd[2176]: Could not generate persistent MAC address for vethadfe8c1: No such file or directory
Mar 18 16:46:35 ollitestd kernel: docker0: port 1(vethadfe8c1) entered blocking state
Mar 18 16:46:35 ollitestd kernel: docker0: port 1(vethadfe8c1) entered disabled state
Mar 18 16:46:35 ollitestd kernel: device vethadfe8c1 entered promiscuous mode
Mar 18 16:46:35 ollitestd dockerd[1510]: time="2021-03-18T16:46:35+01:00" level=error msg="2021/03/18 15:46:35 Entering go-plugins-helpers capabilitiesPath" plugin=fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d
Mar 18 16:46:35 ollitestd dockerd[1510]: time="2021-03-18T16:46:35+01:00" level=error msg="2021/03/18 15:46:35 Entering go-plugins-helpers getPath" plugin=fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d
Mar 18 16:46:35 ollitestd dockerd[1510]: time="2021-03-18T16:46:35+01:00" level=info msg="time=\"2021-03-18T15:46:35Z\" level=info msg=\"Added 1 existing volume(s)\" requestID=de85d0a3-ed31-445f-9fe6-f67e9da97b6e requestSource=Docker" plugin=fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d
Mar 18 16:46:35 ollitestd dockerd[1510]: time="2021-03-18T16:46:35+01:00" level=error msg="2021/03/18 15:46:35 Entering go-plugins-helpers capabilitiesPath" plugin=fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d
Mar 18 16:46:35 ollitestd dockerd[1510]: time="2021-03-18T16:46:35+01:00" level=error msg="2021/03/18 15:46:35 Entering go-plugins-helpers mountPath" plugin=fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d
Mar 18 16:46:36 ollitestd kernel: FS-Cache: Loaded
Mar 18 16:46:36 ollitestd kernel: RPC: Registered named UNIX socket transport module.
Mar 18 16:46:36 ollitestd kernel: RPC: Registered udp transport module.
Mar 18 16:46:36 ollitestd kernel: RPC: Registered tcp transport module.
Mar 18 16:46:36 ollitestd kernel: RPC: Registered tcp NFSv4.1 backchannel transport module.
Mar 18 16:46:36 ollitestd kernel: FS-Cache: Netfs 'nfs' registered for caching
Mar 18 16:46:36 ollitestd kernel: Key type dns_resolver registered
Mar 18 16:46:36 ollitestd kernel: NFS: Registering the id_resolver key type
Mar 18 16:46:36 ollitestd kernel: Key type id_resolver registered
Mar 18 16:46:36 ollitestd kernel: Key type id_legacy registered
Mar 18 16:46:36 ollitestd dockerd[1510]: time="2021-03-18T16:46:36.227005941+01:00" level=info msg="starting signal loop" namespace=moby path=/run/docker/containerd/daemon/io.containerd.runtime.v2.task/moby/5bf5e22038809965bd5fc799f6efa1781388043e342a3cfee5c208f49f00198e pid=2236
Mar 18 16:46:36 ollitestd dockerd[1510]: time="2021-03-18T16:46:36.290961158+01:00" level=error msg="copy shim log" error="read /proc/self/fd/16: file already closed"
Mar 18 16:46:36 ollitestd dockerd[1510]: time="2021-03-18T16:46:36.291841611+01:00" level=error msg="stream copy error: reading from a closed fifo"
Mar 18 16:46:36 ollitestd kernel: docker0: port 1(vethadfe8c1) entered disabled state
Mar 18 16:46:36 ollitestd kernel: device vethadfe8c1 left promiscuous mode
Mar 18 16:46:36 ollitestd kernel: docker0: port 1(vethadfe8c1) entered disabled state
Mar 18 16:46:36 ollitestd dockerd[1510]: time="2021-03-18T16:46:36+01:00" level=error msg="2021/03/18 15:46:36 Entering go-plugins-helpers capabilitiesPath" plugin=fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d
Mar 18 16:46:36 ollitestd dockerd[1510]: time="2021-03-18T16:46:36+01:00" level=error msg="2021/03/18 15:46:36 Entering go-plugins-helpers getPath" plugin=fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d
Mar 18 16:46:36 ollitestd dockerd[1510]: time="2021-03-18T16:46:36+01:00" level=info msg="time=\"2021-03-18T15:46:36Z\" level=info msg=\"Added 1 existing volume(s)\" requestID=48fc6da4-bf18-4710-a067-68df79c6a12a requestSource=Docker" plugin=fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d
Mar 18 16:46:36 ollitestd dockerd[1510]: time="2021-03-18T16:46:36+01:00" level=error msg="2021/03/18 15:46:36 Entering go-plugins-helpers capabilitiesPath" plugin=fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d
Mar 18 16:46:36 ollitestd dockerd[1510]: time="2021-03-18T16:46:36.451426326+01:00" level=error msg="5bf5e22038809965bd5fc799f6efa1781388043e342a3cfee5c208f49f00198e cleanup: failed to delete container from containerd: no such container"
Mar 18 16:46:36 ollitestd dockerd[1510]: time="2021-03-18T16:46:36+01:00" level=error msg="2021/03/18 15:46:36 Entering go-plugins-helpers unmountPath" plugin=fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d
Mar 18 16:46:36 ollitestd dockerd[1510]: time="2021-03-18T16:46:36.454663823+01:00" level=error msg="Handler for POST /v1.41/containers/5bf5e22038809965bd5fc799f6efa1781388043e342a3cfee5c208f49f00198e/start returned error: OCI runtime create failed: container_linux.go:367: starting container process caused: process_linux.go:495: container init caused: rootfs_linux.go:60: mounting \"/icvar/var_lib_docker/plugins/fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d/propagated-mount/ollitestd_test\" to rootfs at \"/data\" caused: stat /icvar/var_lib_docker/plugins/fa0947b2083e4d3d151d68e5ee618b0f7d3cd01aa2dedb9434a38dcbc6865d5d/propagated-mount/ollitestd_test: no such file or directory: unknown"

olivpass avatar Mar 18 '21 15:03 olivpass

Next Debugging:

  • docker version 20.10.5-ce
  • trident-plugin installed with debug=true
user@ollitestd:~> docker plugin install --grant-all-permissions --alias aff3hosts netapp/trident-plugin:21.01.1 config=aff3hosts-config.json debug=true
21.01.1: Pulling from netapp/trident-plugin
Digest: sha256:fa8b0ff414f77abd42372c751d9fff6699845e750289eec0f0da1ffde4c05d9c
1e2da9131277: Complete 
Installed plugin netapp/trident-plugin:21.01.1

Mar 18 17:06:16 ollitestd dockerd[1481]: time="2021-03-18T17:06:16+01:00" level=error msg="2021/03/18 16:06:16 Entering go-plugins-helpers mountPath" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:06:16 ollitestd dockerd[1481]: time="2021-03-18T17:06:16+01:00" level=info msg="time=\"2021-03-18T16:06:16Z\" level=debug msg=\"Docker frontend method is invoked.\" id=855245f4107a9f14c444bb8bfc72f825a40670018fc501ddf4ed9239b0e443e0 method=Mount name=test requestID=df328436-265f-4afd-9655-dff0cdb21780 requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:06:16 ollitestd dockerd[1481]: time="2021-03-18T17:06:16+01:00" level=info msg="time=\"2021-03-18T16:06:16Z\" level=debug msg=\"Attempting volume publish.\" backend=ontapnas_172.16.12.247 backendUUID= requestID=df328436-265f-4afd-9655-dff0cdb21780 requestSource=Docker volume=test volumeInternal=ollitestd_test" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:06:16 ollitestd dockerd[1481]: time="2021-03-18T17:06:16+01:00" level=info msg="time=\"2021-03-18T16:06:16Z\" level=debug msg=\"Mounting volume.\" hostMountpoint=/host/var_lib_docker/plugins/a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899/propagated-mount/ollitestd_test isDockerPluginModeSet=true mountpoint=/var_lib_docker/plugins/a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899/propagated-mount/ollitestd_test requestID=df328436-265f-4afd-9655-dff0cdb21780 requestSource=Docker volume=test" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899

There is Mounting volume. definitely wrong: /host/var_lib_docker/plugins/.... In my case it perhaps should be /host/icvar/var_lib_docker/plugins/....

With this Information, i am shure, you know if this is a docker or a trident mistake ;-) Thank you

olivpass avatar Mar 18 '21 16:03 olivpass

More Infos:

Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /var_lib_docker/plugins/a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899/rootfs, mountPoint: /\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /, mountPoint: /proc\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /, mountPoint: /dev\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /, mountPoint: /dev/pts\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /, mountPoint: /sys\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /, mountPoint: /sys/fs/cgroup\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /system.slice/docker.service/a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899, mountPoint: /sys/fs/cgroup/systemd\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /system.slice/docker.service/a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899, mountPoint: /sys/fs/cgroup/devices\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899, mountPoint: /sys/fs/cgroup/cpuset\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899, mountPoint: /sys/fs/cgroup/hugetlb\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /system.slice/docker.service/a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899, mountPoint: /sys/fs/cgroup/cpu,cpuacct\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899, mountPoint: /sys/fs/cgroup/net_cls,net_prio\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /, mountPoint: /sys/fs/cgroup/rdma\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /system.slice/docker.service/a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899, mountPoint: /sys/fs/cgroup/memory\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /system.slice/docker.service/a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899, mountPoint: /sys/fs/cgroup/pids\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899, mountPoint: /sys/fs/cgroup/freezer\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899, mountPoint: /sys/fs/cgroup/perf_event\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /system.slice/docker.service/a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899, mountPoint: /sys/fs/cgroup/blkio\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /, mountPoint: /dev/mqueue\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /, mountPoint: /dev/shm\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"root: /var_lib_docker/plugins/a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899/propagated-mount, mountPoint: /var/lib/docker-volumes/netapp\\n\" requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899

ollitestd:/ # journalctl -b 0 | grep plugin.hostVolumePath
Mar 18 17:05:41 ollitestd dockerd[1481]: time="2021-03-18T17:05:41+01:00" level=info msg="time=\"2021-03-18T16:05:41Z\" level=debug msg=\"Running in Docker plugin mode.\" plugin.hostVolumePath=/var_lib_docker/plugins/a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899/propagated-mount plugin.volumePath=/var/lib/docker-volumes/netapp requestID=5550e647-005e-418d-bd83-bd808e29360a requestSource=Docker" plugin=a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899

I read the code and found following lines:

cat vi ./utils/k8s_utils.go
...
// listProcSelfMountinfo (Available since Linux 2.6.26) lists information about mount points
// in the process's mount namespace. Ref: http://man7.org/linux/man-pages/man5/proc.5.html
// for /proc/[pid]/mountinfo
func listProcSelfMountinfo(mountFilePath string) ([]MountInfo, error) {
        content, err := ConsistentRead(mountFilePath, maxListTries)
        if err != nil {
                return nil, err
        }
        return parseProcSelfMountinfo(content)
}

// parseProcSelfMountinfo parses the output of /proc/self/mountinfo file into a slice of MountInfo struct
func parseProcSelfMountinfo(content []byte) ([]MountInfo, error) {
        out := make([]MountInfo, 0)
        lines := strings.Split(string(content), "\n")
        for _, line := range lines {
                if line == "" {
                        // The last split() item is empty string following the last \n
...

On my host, i get following:

ollitestd:/ # cat /proc/$$/mountinfo
...
109 94 8:2 / /boot/efi rw,relatime shared:29 - vfat /dev/sda2 rw,fmask=0022,dmask=0022,codepage=437,iocharset=iso8859-1,shortname=mixed,errors=remount-ro
112 94 8:17 / /icvar rw,relatime shared:30 - xfs /dev/sdb1 rw,attr2,inode64,logbufs=8,logbsize=32k,noquota
185 112 8:17 /var_lib_docker/plugins/a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899/propagated-mount /icvar/var_lib_docker/plugins/a20d092ca66f6ea771ca42cf73d20d4acac4135acae773a3d5144fab1d099899/propagated-mount rw,relatime shared:30 - xfs /dev/sdb1 rw,attr2,inode64,logbufs=8,logbsize=32k,noquota
190 29 0:52 / /run/user/1000 rw,nosuid,nodev,relatime shared:71 - tmpfs tmpfs rw,size=202612k,mode=700,uid=1000,gid=100

The documentation for /proc/$$/mountinfo: https://www.kernel.org/doc/Documentation/filesystems/proc.txt

This file contains lines of the form:

36 35 98:0 /mnt1 /mnt2 rw,noatime master:1 - ext3 /dev/root rw,errors=continue
(1)(2)(3)   (4)   (5)      (6)      (7)   (8) (9)   (10)         (11)
...
(4) root:  root of the mount within the filesystem
(5) mount point:  mount point relative to the process's root
...

maybe you should use (5) and not (4)?

olivpass avatar Mar 18 '21 16:03 olivpass

@olivpass,

Thanks for the feedback. We'll look into this again.

gnarl avatar Mar 18 '21 17:03 gnarl

Hello,

I still don't know whether this problem is related to trident or the docker daemon itself, but we have a very similiar issue which was actually not related to the --data-dir flag though matching the behaviour mentioned in the first comment.

The path to the mountpoint of the filesystem where docker "lives" seems to be stripped from the mountpoint for the trident volume.

Examples: We started with an extra filesystem mounted to /var and the volume used via the trident driver was mounted to /lib/docker/plugins/SOMEID/propagated-mount/VOLUME( as /lib was a symlink it was mounted to /usr/lib/docker/... )

To prove the point i created a new filesystem and mounted it to /var/lib/docker and the volume mount was done under /plugins/SOMEID/propagated-mount/VOLUME

I hope this helps in some way.

We worked around this problem by bind-mounting /var/lib/docker to /usr/lib/docker though this is far from an ideal solution.

rhld-linux avatar Nov 29 '21 10:11 rhld-linux

This issue is fixed with commit 7842b3f and will be included in the Trident v22.10 release.

gnarl avatar Oct 17 '22 16:10 gnarl