2017-08-18 01:07:39.366134258 -0700 PDT [INFO] No config file found. Using defaults. 2017-08-18 01:07:39.370415554 -0700 PDT [WARNING] Failed to load config file /etc/docker-volume-vsphere.conf: open /etc/docker-volume-vsphere.conf: no such file or directory 2017-08-18 01:07:39.370471689 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-08-18 01:07:39.370486324 -0700 PDT [INFO] Plugin options - port=1019 2017-08-18 01:07:39.370498857 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-08-18 01:07:39.383203562 -0700 PDT [INFO] Found 0 running or paused containers 2017-08-18 01:07:39.38348736 -0700 PDT [INFO] Discovered 0 volumes in use. 2017-08-18 01:07:39.383502778 -0700 PDT [INFO] Refcounting successfully completed 2017-08-18 01:07:39.383512542 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.4" port=1019 mock_esx=false 2017-08-18 01:07:39.383711397 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-08-18 01:08:53.40552554 -0700 PDT [INFO] Removing volume name="TestVolume123@shared Vmfs - 0" 2017-08-18 01:08:53.758622799 -0700 PDT [INFO] Removing volume name="TestVolumexxxxx@shared Vmfs - 0" 2017-08-18 01:08:54.131236737 -0700 PDT [INFO] Removing volume name="Volume1@shared Vmfs - 0" 2017-08-18 01:08:54.561704785 -0700 PDT [INFO] Removing volume name="VolumeABC@local.3-1" 2017-08-18 01:08:54.90239015 -0700 PDT [INFO] Removing volume name="vsphere15VOL1@shared Vmfs - 0" 2017-08-18 01:11:19.276894789 -0700 PDT [INFO] Attaching volume and creating filesystem name=VolXYZ1 fstype=ext4 2017-08-18 01:11:26.985590562 -0700 PDT [INFO] Scan complete device="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0" event="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0": 0x100 == IN_CREATE 2017-08-18 01:11:28.256493623 -0700 PDT [INFO] Volume and filesystem created name=VolXYZ1 fstype=ext4 2017-08-18 01:13:17.583099337 -0700 PDT [INFO] Mounting volume name="VolXYZ1@shared Vmfs - 0" 2017-08-18 01:13:18.108556925 -0700 PDT [INFO] Scan complete event="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0": 0x100 == IN_CREATE device="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0" 2017-08-18 01:14:47.0780024 -0700 PDT [WARNING] Received signal signal=terminated 2017-08-18 01:25:41.600052731 -0700 PDT [INFO] No config file found. Using defaults. 2017-08-18 01:25:41.600162458 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-08-18 01:25:41.600321055 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-08-18 01:25:41.614066399 -0700 PDT [INFO] Found 1 running or paused containers 2017-08-18 01:25:41.638001413 -0700 PDT [INFO] Mounts read successfullydata="/dev/disk/by-uuid/66a21986-55c4-4ede-a2d9-37d30aa41a8e / ext4 rw,relatime,errors=remount-ro,data=ordered 0 0\n/dev/disk/by-uuid/66a21986-55c4-4ede-a2d9-37d30aa41a8e /mnt/vmdk ext4 rw,relatime,errors=remount-ro,data=ordered 0 0\n/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0 /mnt/vmdk/VolXYZ1@shared\\040\\040\\040\\040Vmfs\\040\\040\\040-\\040\\040\\0400 ext4 rw,relatime,data=ordered 0 0\nproc /proc proc rw,nosuid,nodev,noexec,relatime 0 0\ntmpfs /dev tmpfs rw,nosuid,mode=755 0 0\ndevpts /dev/pts devpts rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=666 0 0\nsysfs /sys sysfs ro,nosuid,nodev,noexec,relatime 0 0\ntmpfs /sys/fs/cgroup tmpfs ro,nosuid,nodev,noexec,relatime,mode=755 0 0\ncgroup /sys/fs/cgroup/cpuset cgroup ro,nosuid,nodev,noexec,relatime,cpuset 0 0\ncgroup /sys/fs/cgroup/cpu cgroup ro,nosuid,nodev,noexec,relatime,cpu 0 0\ncgroup /sys/fs/cgroup/cpuacct cgroup ro,nosuid,nodev,noexec,relatime,cpuacct 0 0\ncgroup /sys/fs/cgroup/blkio cgroup ro,nosuid,nodev,noexec,relatime,blkio 0 0\ncgroup /sys/fs/cgroup/memory cgroup ro,nosuid,nodev,noexec,relatime,memory 0 0\ncgroup /sys/fs/cgroup/devices cgroup ro,nosuid,nodev,noexec,relatime,devices 0 0\ncgroup /sys/fs/cgroup/freezer cgroup ro,nosuid,nodev,noexec,relatime,freezer 0 0\ncgroup /sys/fs/cgroup/net_cls cgroup ro,nosuid,nodev,noexec,relatime,net_cls 0 0\ncgroup /sys/fs/cgroup/perf_event cgroup ro,nosuid,nodev,noexec,relatime,perf_event 0 0\ncgroup /sys/fs/cgroup/net_prio cgroup ro,nosuid,nodev,noexec,relatime,net_prio 0 0\ncgroup /sys/fs/cgroup/hugetlb cgroup ro,nosuid,nodev,noexec,relatime,hugetlb 0 0\nsystemd /sys/fs/cgroup/systemd cgroup ro,nosuid,nodev,noexec,relatime,name=systemd 0 0\nmqueue /dev/mqueue mqueue rw,nosuid,nodev,noexec,relatime 0 0\nudev /dev devtmpfs rw,relatime,size=2012868k,nr_inodes=503217,mode=755 0 0\ndevpts /dev/pts devpts rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000 0 0\ntmpfs /var/run tmpfs rw,nosuid,noexec,relatime,size=404732k,mode=755 0 0\nnone /var/run/lock tmpfs rw,nosuid,nodev,noexec,relatime,size=5120k 0 0\nnone /var/run/shm tmpfs rw,nosuid,nodev,relatime 0 0\nnone /var/run/user tmpfs rw,nosuid,nodev,noexec,relatime,size=102400k,mode=755 0 0\nnsfs /var/run/docker/netns/10a9d1c8ea65 nsfs rw 0 0\n/dev/disk/by-uuid/66a21986-55c4-4ede-a2d9-37d30aa41a8e /etc ext4 rw,relatime,errors=remount-ro,data=ordered 0 0\n/dev/disk/by-uuid/66a21986-55c4-4ede-a2d9-37d30aa41a8e /var/log ext4 rw,relatime,errors=remount-ro,data=ordered 0 0\ntmpfs /run/docker/plugins tmpfs rw,nosuid,noexec,relatime,size=404732k,mode=755 0 0\nproc /proc/bus proc ro,nosuid,nodev,noexec,relatime 0 0\nproc /proc/fs proc ro,nosuid,nodev,noexec,relatime 0 0\nproc /proc/irq proc ro,nosuid,nodev,noexec,relatime 0 0\nproc /proc/sys proc ro,nosuid,nodev,noexec,relatime 0 0\nproc /proc/sysrq-trigger proc ro,nosuid,nodev,noexec,relatime 0 0\nudev /proc/kcore devtmpfs rw,relatime,size=2012868k,nr_inodes=503217,mode=755 0 0\nudev /proc/timer_list devtmpfs rw,relatime,size=2012868k,nr_inodes=503217,mode=755 0 0\nudev /proc/timer_stats devtmpfs rw,relatime,size=2012868k,nr_inodes=503217,mode=755 0 0\nudev /proc/sched_debug devtmpfs rw,relatime,size=2012868k,nr_inodes=503217,mode=755 0 0\ntmpfs /sys/firmware tmpfs ro,relatime 0 0\n" 2017-08-18 01:25:41.638194455 -0700 PDT [INFO] Successfully retrieved mountsmap=map[VolXYZ1@shared\040\040\040\040Vmfs\040\040\040-\040\040\0400:/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0] 2017-08-18 01:25:41.638214387 -0700 PDT [WARNING] Initiating recovery mount. refcnt=1 mounted=false dev= name="VolXYZ1@shared Vmfs - 0" 2017-08-18 01:25:52.748788376 -0700 PDT [WARNING] Exceeded timeout while waiting for device attach to completetimeout=10s device="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0" 2017-08-18 01:25:52.748992104 -0700 PDT [WARNING] Failed to mount - manual recovery may be needed 2017-08-18 01:25:52.749007513 -0700 PDT [INFO] Initiating recovery unmount. name="VolXYZ1@shared\\040\\040\\040\\040Vmfs\\040\\040\\040-\\040\\040\\0400" refcnt=0 mounted=true dev="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0" 2017-08-18 01:25:52.749063339 -0700 PDT [ERROR] Failed to unmount volume. Now trying to detach... mountpoint="/mnt/vmdk/VolXYZ1@shared\\040\\040\\040\\040Vmfs\\040\\040\\040-\\040\\040\\0400" error="Unmount device at /mnt/vmdk/VolXYZ1@shared\\040\\040\\040\\040Vmfs\\040\\040\\040-\\040\\040\\0400 failed: no such file or directory" 2017-08-18 01:25:53.116348773 -0700 PDT [WARNING] Failed to unmount - manual recovery may be needed 2017-08-18 01:25:53.116391852 -0700 PDT [INFO] Discovered 2 volumes in use. 2017-08-18 01:25:53.116402732 -0700 PDT [INFO] Volume name=VolXYZ1@shared Vmfs - 0 count=1 mounted=false device='' 2017-08-18 01:25:53.116409306 -0700 PDT [INFO] Volume name=VolXYZ1@shared\040\040\040\040Vmfs\040\040\040-\040\040\0400 count=0 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-08-18 01:25:53.116415015 -0700 PDT [INFO] Refcounting successfully completed 2017-08-18 01:25:53.116444672 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-08-18 01:25:53.116512388 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-08-18 01:32:14.465078092 -0700 PDT [WARNING] Received signal signal=terminated 2017-08-18 01:36:16.410368993 -0700 PDT [INFO] No config file found. Using defaults. 2017-08-18 01:36:16.410426471 -0700 PDT [WARNING] Failed to load config file /etc/docker-volume-vsphere.conf: open /etc/docker-volume-vsphere.conf: no such file or directory 2017-08-18 01:36:16.410435146 -0700 PDT [INFO] Starting plugin log_level=info config="/etc/docker-volume-vsphere.conf" driver=vsphere 2017-08-18 01:36:16.410480374 -0700 PDT [INFO] Plugin options - port=1019 2017-08-18 01:36:16.410494629 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-08-18 01:36:16.426732041 -0700 PDT [INFO] Found 0 running or paused containers 2017-08-18 01:36:16.427021038 -0700 PDT [INFO] Discovered 0 volumes in use. 2017-08-18 01:36:16.427055795 -0700 PDT [INFO] Refcounting successfully completed 2017-08-18 01:36:16.427066139 -0700 PDT [INFO] Docker VMDK plugin started port=1019 mock_esx=false version="vSphere Volume Driver v0.4" 2017-08-18 01:36:16.427341015 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-08-18 01:37:02.622134805 -0700 PDT [INFO] Mounting volume name="VolXYZ1@shared Vmfs - 0" 2017-08-18 01:37:12.968753329 -0700 PDT [WARNING] Exceeded timeout while waiting for device attach to completetimeout=10s device="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0" 2017-08-18 01:38:47.008008621 -0700 PDT [WARNING] Received signal signal=terminated 2017-08-18 01:39:53.608056794 -0700 PDT [INFO] No config file found. Using defaults. 2017-08-18 01:39:53.608128184 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-08-18 01:39:53.608155044 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-08-18 01:39:53.622314673 -0700 PDT [INFO] Found 1 running or paused containers 2017-08-18 01:39:53.660061969 -0700 PDT [INFO] Mounts read successfullydata="/dev/disk/by-uuid/66a21986-55c4-4ede-a2d9-37d30aa41a8e / ext4 rw,relatime,errors=remount-ro,data=ordered 0 0\n/dev/disk/by-uuid/66a21986-55c4-4ede-a2d9-37d30aa41a8e /mnt/vmdk ext4 rw,relatime,errors=remount-ro,data=ordered 0 0\n/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0 /mnt/vmdk/VolXYZ1@shared\\040\\040\\040\\040Vmfs\\040\\040\\040-\\040\\040\\0400 ext4 rw,relatime,data=ordered 0 0\nproc /proc proc rw,nosuid,nodev,noexec,relatime 0 0\ntmpfs /dev tmpfs rw,nosuid,mode=755 0 0\ndevpts /dev/pts devpts rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=666 0 0\nsysfs /sys sysfs ro,nosuid,nodev,noexec,relatime 0 0\ntmpfs /sys/fs/cgroup tmpfs ro,nosuid,nodev,noexec,relatime,mode=755 0 0\ncgroup /sys/fs/cgroup/cpuset cgroup ro,nosuid,nodev,noexec,relatime,cpuset 0 0\ncgroup /sys/fs/cgroup/cpu cgroup ro,nosuid,nodev,noexec,relatime,cpu 0 0\ncgroup /sys/fs/cgroup/cpuacct cgroup ro,nosuid,nodev,noexec,relatime,cpuacct 0 0\ncgroup /sys/fs/cgroup/blkio cgroup ro,nosuid,nodev,noexec,relatime,blkio 0 0\ncgroup /sys/fs/cgroup/memory cgroup ro,nosuid,nodev,noexec,relatime,memory 0 0\ncgroup /sys/fs/cgroup/devices cgroup ro,nosuid,nodev,noexec,relatime,devices 0 0\ncgroup /sys/fs/cgroup/freezer cgroup ro,nosuid,nodev,noexec,relatime,freezer 0 0\ncgroup /sys/fs/cgroup/net_cls cgroup ro,nosuid,nodev,noexec,relatime,net_cls 0 0\ncgroup /sys/fs/cgroup/perf_event cgroup ro,nosuid,nodev,noexec,relatime,perf_event 0 0\ncgroup /sys/fs/cgroup/net_prio cgroup ro,nosuid,nodev,noexec,relatime,net_prio 0 0\ncgroup /sys/fs/cgroup/hugetlb cgroup ro,nosuid,nodev,noexec,relatime,hugetlb 0 0\nsystemd /sys/fs/cgroup/systemd cgroup ro,nosuid,nodev,noexec,relatime,name=systemd 0 0\nmqueue /dev/mqueue mqueue rw,nosuid,nodev,noexec,relatime 0 0\nudev /dev devtmpfs rw,relatime,size=2012868k,nr_inodes=503217,mode=755 0 0\ndevpts /dev/pts devpts rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000 0 0\ntmpfs /var/run tmpfs rw,nosuid,noexec,relatime,size=404732k,mode=755 0 0\nnone /var/run/lock tmpfs rw,nosuid,nodev,noexec,relatime,size=5120k 0 0\nnone /var/run/shm tmpfs rw,nosuid,nodev,relatime 0 0\nnone /var/run/user tmpfs rw,nosuid,nodev,noexec,relatime,size=102400k,mode=755 0 0\nnsfs /var/run/docker/netns/a70ea237d5c5 nsfs rw 0 0\n/dev/disk/by-uuid/66a21986-55c4-4ede-a2d9-37d30aa41a8e /etc ext4 rw,relatime,errors=remount-ro,data=ordered 0 0\n/dev/disk/by-uuid/66a21986-55c4-4ede-a2d9-37d30aa41a8e /var/log ext4 rw,relatime,errors=remount-ro,data=ordered 0 0\ntmpfs /run/docker/plugins tmpfs rw,nosuid,noexec,relatime,size=404732k,mode=755 0 0\nproc /proc/bus proc ro,nosuid,nodev,noexec,relatime 0 0\nproc /proc/fs proc ro,nosuid,nodev,noexec,relatime 0 0\nproc /proc/irq proc ro,nosuid,nodev,noexec,relatime 0 0\nproc /proc/sys proc ro,nosuid,nodev,noexec,relatime 0 0\nproc /proc/sysrq-trigger proc ro,nosuid,nodev,noexec,relatime 0 0\nudev /proc/kcore devtmpfs rw,relatime,size=2012868k,nr_inodes=503217,mode=755 0 0\nudev /proc/timer_list devtmpfs rw,relatime,size=2012868k,nr_inodes=503217,mode=755 0 0\nudev /proc/timer_stats devtmpfs rw,relatime,size=2012868k,nr_inodes=503217,mode=755 0 0\nudev /proc/sched_debug devtmpfs rw,relatime,size=2012868k,nr_inodes=503217,mode=755 0 0\ntmpfs /sys/firmware tmpfs ro,relatime 0 0\n" 2017-08-18 01:39:53.660400439 -0700 PDT [INFO] Successfully retrieved mountsmap=map[VolXYZ1@shared\040\040\040\040Vmfs\040\040\040-\040\040\0400:/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0] 2017-08-18 01:39:53.660430455 -0700 PDT [INFO] Initiating recovery unmount. name="VolXYZ1@shared\\040\\040\\040\\040Vmfs\\040\\040\\040-\\040\\040\\0400" refcnt=0 mounted=true dev="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0" 2017-08-18 01:39:53.660459208 -0700 PDT [ERROR] Failed to unmount volume. Now trying to detach... error="Unmount device at /mnt/vmdk/VolXYZ1@shared\\040\\040\\040\\040Vmfs\\040\\040\\040-\\040\\040\\0400 failed: no such file or directory" mountpoint="/mnt/vmdk/VolXYZ1@shared\\040\\040\\040\\040Vmfs\\040\\040\\040-\\040\\040\\0400" 2017-08-18 01:39:54.368450801 -0700 PDT [WARNING] Failed to unmount - manual recovery may be needed 2017-08-18 01:39:54.368763514 -0700 PDT [WARNING] Initiating recovery mount. name="VolXYZ1@shared Vmfs - 0" refcnt=1 mounted=false dev= 2017-08-18 01:40:04.873214927 -0700 PDT [WARNING] Exceeded timeout while waiting for device attach to completedevice="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0" timeout=10s 2017-08-18 01:40:04.873631738 -0700 PDT [WARNING] Failed to mount - manual recovery may be needed 2017-08-18 01:40:04.873680592 -0700 PDT [INFO] Discovered 2 volumes in use. 2017-08-18 01:40:04.873699227 -0700 PDT [INFO] Volume name=VolXYZ1@shared Vmfs - 0 count=1 mounted=false device='' 2017-08-18 01:40:04.873717997 -0700 PDT [INFO] Volume name=VolXYZ1@shared\040\040\040\040Vmfs\040\040\040-\040\040\0400 count=0 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-08-18 01:40:04.873776643 -0700 PDT [INFO] Refcounting successfully completed 2017-08-18 01:40:04.873809598 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-08-18 01:40:04.874059974 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock"