flexvolume-debugging-notes.md

Flexvolume notes

• Steps takes to attempt to get FlexVolume working in Kubernetes 1.6.6, 1.7.1, and 1.7.4
• Test performed in Vagrant with 1 node (w1)

Environment

$ kubectl version
Client Version: version.Info{Major:"1", Minor:"6", GitVersion:"v1.6.6", GitCommit:"7fa1c1756d8bc963f1a389f4a6937dc71f08ada2", GitTreeState:"clean", BuildDate:"2017-06-16T18:34:20Z", GoVersion:"go1.7.6", Compiler:"gc", Platform:"linux/amd64"}
Server Version: version.Info{Major:"1", Minor:"6", GitVersion:"v1.6.6", GitCommit:"7fa1c1756d8bc963f1a389f4a6937dc71f08ada2", GitTreeState:"clean", BuildDate:"2017-06-16T18:21:54Z", GoVersion:"go1.7.6", Compiler:"gc", Platform:"linux/amd64"}

$ vagrant version
Installed Version: 1.8.5

$ virtualbox version
5.1.6

# Vagrant box
config.vm.box = "ubuntu/xenial64"

On NODE (named w1)

# create driver in the default flexvolume driver path that Kubelet knows about
mkdir -p /usr/libexec/kubernetes/kubelet-plugins/volume/exec/kubernetes.io~lvm

# Copy lvm driver into above created path: https://github.com/kubernetes/kubernetes/blob/master/examples/volumes/flexvolume/lvm
# Add at line 145 for debugging: echo `date` "Recevied argument $1" >> /tmp/lvm.log
chmod 755 /usr/libexec/kubernetes/kubelet-plugins/volume/exec/kubernetes.io~lvm/lvm

Enable Alpha features on Node

# Kubelet on Node, enable alpha features and increase debugging verbosity.
# FYI: setting attach-detach to true (default) also did not help in getting flexvolume working

vim /etc/systemd/system/kubelet.service.d/override.conf
Environment='KUBELET_EXTRA_ARGS=--feature-gates="AllAlpha=true" -v=6 --enable-controller-attach-detach=false --pod-infra-container-image artprod.dev.bloomberg.com/ds/ext/gcr.io/google_containers/pause-amd64:3.0'
systemctl force-reload systemd-journald; systemctl restart systemd-journald

On MASTER

# set label on node in case more nodes exist in cluster
kubectl label nodes w1 fuse=true

# Copy and amend POD nginx example with NodeSelector
POD: https://github.com/kubernetes/kubernetes/blob/master/examples/volumes/flexvolume/nginx.yaml
# Set this as nodeSelector
  nodeSelector:
    fuse: "true"

# Create POD and see if lvm flexvolume gets created
kubectl create -f nginx.yaml

Now time time test and see if it works

# Watch POD get created
watch -n 1 'kubectl describe pod nginx | tail -5'

# After a minute, there is a timeout seen when describing the POD
  FirstSeen     LastSeen        Count   From                    SubObjectPath   Type            Reason          Message
  ---------     --------        -----   ----                    -------------   --------        ------          -------
  14m           14m             1       default-scheduler                       Normal          Scheduled       Successfully assigned nginx to w1
  12m           1m              6       kubelet, w1                             Warning         FailedMount     Unable to mount volumes for pod "nginx_default(243a6517-9309-11e7-82b
8-0246137976e5)": timeout expired waiting for volumes to attach/mount for pod "default"/"nginx". list of unattached/unmounted volumes=[test]
  12m           1m              6       kubelet, w1                             Warning         FailedSync      Error syncing pod, skipping: timeout expired waiting for volumes to a
ttach/mount for pod "default"/"nginx". list of unattached/unmounted volumes=[test]

on Node

# Since we added debugging to the lvm driver, check to see if our lvm driver was called, and with what arguments.
# We can see it was only called with "init" (during kubelet start) and "getvolumename" during POD creation. Never with either "mountdevice", "isattached", or anything else for that matter.
cat /tmp/lvm.log
Wed Sep 6 13:35:38 UTC 2017 Recevied argument init
Wed Sep 6 13:35:43 UTC 2017 Recevied argument getvolumename

# journalctl only shows the following entry even with log verbosity set to 6
journalctl -ex -u kubelet
Sep 06 13:57:54 w1 kubelet[8287]: I0906 13:57:54.473044    8287 reconciler.go:242] VerifyControllerAttachedVolume operation started for volume "kubernetes.io/lvm/test" (spec.Name: "test") pod "5ab98254-930b-11e7-82b8-0246137976e5" (UID: "5ab98254-930b-11e7-82b8-0246137976e5")
Sep 06 13:57:54 w1 kubelet[8287]: E0906 13:57:54.475425    8287 nestedpendingoperations.go:262] Operation for "\"kubernetes.io/lvm/test\"" failed. No retries permitted until 2017-09-06 13:59:54.475410348 +0000 UTC (durationBeforeRetry 2m0s). Error: Volume "kubernetes.io/lvm/test" (spec.Name: "test") pod "5ab98254-930b-11e7-82b8-0246137976e5" (UID: "5ab98254-930b-11e7-82b8-0246137976e5") is not yet attached according to node status