ssh keys are not mounted through boot2docker VM disk image

[davidovich]

Is this a BUG REPORT:

We have intermittent ssh connectivity issues affecting any future machine provisioning operations. This happens for us primarily on hyperv and Windows, but I believe it could be reproduced on other systems, as I think the systemd initialization order is broken.

Environment:

Minikube version: 0.28.2

• OS Windows:
• VM Driver hyperv
• ISO version 0.28.1:

What happened:

I seems that the automount script can be run before the device is mounted by the virtual machine manager. Although I cannot explain jounralctl timestamps differences (leap from 17:00 to 21:00) (which could have an impact), you can see that the minikube-automount happens before the device sda (.vhd mount) is mounted.

In a minikube VM I ran journalctl. Notice the UNPARTITIONED_HD variable which does not contain the sda device, as it is not available at that time.

$ journalctl -u minikube-automount
-- Logs begin at Tue 2018-09-25 17:00:06 UTC, end at Tue 2018-09-25 21:17:18 UTC. --
Sep 25 17:00:07 minikube systemd[1]: Starting minikube automount...
Sep 25 17:00:07 minikube minikube-automount[2030]: + echo 'automount ...'
Sep 25 17:00:07 minikube minikube-automount[2030]: automount ...
Sep 25 17:00:07 minikube minikube-automount[2030]: + LABEL=boot2docker-data
Sep 25 17:00:07 minikube minikube-automount[2030]: + MAGIC='boot2docker, please format-me'
Sep 25 17:00:07 minikube minikube-automount[2030]: ++ blkid -o device -l -t LABEL=boot2docker-data
Sep 25 17:00:07 minikube minikube-automount[2030]: + BOOT2DOCKER_DATA=
Sep 25 17:00:07 minikube minikube-automount[2030]: ++ lsblk
Sep 25 17:00:07 minikube minikube-automount[2030]: ++ grep disk
Sep 25 17:00:07 minikube minikube-automount[2030]: ++ cut -f1 '-d '
Sep 25 17:00:07 minikube minikube-automount[2030]: + UNPARTITIONED_HD=/dev/
Sep 25 17:00:07 minikube minikube-automount[2030]: + echo
Sep 25 17:00:07 minikube minikube-automount[2030]: + '[' '!' -n '' ']'
Sep 25 17:00:07 minikube minikube-automount[2030]: + echo 'Is the disk unpartitioned?, test for the '\''boot2docker format-me'\'' string'
Sep 25 17:00:07 minikube minikube-automount[2030]: Is the disk unpartitioned?, test for the 'boot2docker format-me' string
Sep 25 17:00:07 minikube minikube-automount[2030]: + grep 'Partition Table: unknown'
Sep 25 17:00:07 minikube minikube-automount[2030]: + parted --script /dev/ print
Sep 25 17:00:07 minikube minikube-automount[2030]: Warning: Unable to open /dev read-write (Is a directory).  /dev has been opened read-only.
Sep 25 17:00:07 minikube minikube-automount[2030]: Error: /dev: unrecognised disk label
Sep 25 17:00:07 minikube minikube-automount[2030]: Partition Table: unknown
Sep 25 17:00:07 minikube minikube-automount[2030]: + '[' 0 -eq 0 ']'
Sep 25 17:00:07 minikube minikube-automount[2030]: ++ dd if=/dev/ bs=1 count=29
Sep 25 17:00:07 minikube minikube-automount[2030]: + HEADER=
Sep 25 17:00:07 minikube minikube-automount[2030]: + '[' '' = 'boot2docker, please format-me' ']'
Sep 25 17:00:07 minikube minikube-automount[2030]: +++ basename /dev/ /dev/
Sep 25 17:00:07 minikube minikube-automount[2030]: ++ tr -d '\n'
Sep 25 17:00:07 minikube minikube-automount[2030]: +++ basename /dev/ /dev/
Sep 25 17:00:07 minikube minikube-automount[2030]: ++ cat /sys/class/block/dev/device/vendor /sys/class/block/dev/device/model
Sep 25 17:00:07 minikube minikube-automount[2030]: cat: /sys/class/block/dev/device/vendor: No such file or directory
Sep 25 17:00:07 minikube minikube-automount[2030]: cat: /sys/class/block/dev/device/model: No such file or directory
Sep 25 17:00:07 minikube minikube-automount[2030]: + DISK_VENDOR=
Sep 25 17:00:07 minikube minikube-automount[2030]: + '[' '' = 'VMware, VMware Virtual S' ']'
Sep 25 17:00:07 minikube minikube-automount[2030]: + '[' '' = 'VMware  Virtual disk    ' ']'
Sep 25 17:00:07 minikube minikube-automount[2030]: + echo
Sep 25 17:00:07 minikube minikube-automount[2030]: + '[' -n '' ']'
Sep 25 17:00:07 minikube minikube-automount[2030]: + swapon /dev/2
Sep 25 17:00:07 minikube minikube-automount[2030]: swapon: cannot open /dev/2: No such file or directory
Sep 25 17:00:07 minikube minikube-automount[2030]: + mkdir -p /var/lib/boot2docker/etc/
Sep 25 17:00:07 minikube minikube-automount[2030]: + modprobe vboxguest
Sep 25 21:00:07 minikube minikube-automount[2030]: + '[' -e /var/lib/boot2docker/bootlocal.sh ']'
Sep 25 21:00:10 minikube systemd[1]: Started minikube automount.

Here is the relevant device mount operations. Notice the timestamps:

Sep 25 21:00:10 minikube kernel: scsi host2: storvsc_host_t
Sep 25 21:00:10 minikube kernel: scsi 2:0:0:0: Direct-Access     Msft     Virtual Disk     1.0  PQ: 0 ANSI: 5
Sep 25 21:00:10 minikube kernel: sd 2:0:0:0: Attached scsi generic sg1 type 0
Sep 25 21:00:10 minikube kernel: sd 2:0:0:0: [sda] 81920000 512-byte logical blocks: (41.9 GB/39.1 GiB)
Sep 25 21:00:10 minikube kernel: sd 2:0:0:0: [sda] Write Protect is off
Sep 25 21:00:10 minikube kernel: sd 2:0:0:0: [sda] Mode Sense: 0f 00 00 00
Sep 25 21:00:10 minikube kernel: scsi host3: storvsc_host_t
Sep 25 21:00:10 minikube kernel: sd 2:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Sep 25 21:00:10 minikube kernel: hv_utils: VSS IC version 5.0
Sep 25 21:00:10 minikube kernel: sd 2:0:0:0: [sda] Attached SCSI disk

After sshing into the VM, the device is there (but too late).

$ lsblk | grep disk | cut -f1 -d' '
sda

What you expected to happen:

I expect that the automount script be run after the /dev/sda device (in my case) is available.

How to reproduce it (as minimally and precisely as possible):

As this is a kind of race, it is reproductible only about 30-40%, but a simple:

minikube start --vm-driver hyperv --disk-size 40g --hyperv-virtual-switch "Default Switch"

Anything else do we need to know:

Not very knowledgeable on systemd, but I will try adding RequiresMountsFor=/dev to the [Unit] clause to see if this fixes the problem.