2017-07-10 21:38:10.889055455 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-10 21:38:10.88932327 -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-07-10 21:38:10.889348646 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-10 21:38:10.889381013 -0700 PDT [INFO] Plugin options - port=1019 2017-07-10 21:38:10.889398895 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 21:38:10.913398167 -0700 PDT [INFO] Found 0 running or paused containers 2017-07-10 21:38:10.913629545 -0700 PDT [INFO] Discovered 0 volumes in use. 2017-07-10 21:38:10.913642097 -0700 PDT [INFO] Refcounting successfully completed 2017-07-10 21:38:10.913652038 -0700 PDT [INFO] Docker VMDK plugin started port=1019 mock_esx=false version="vSphere Volume Driver v0.5" 2017-07-10 21:38:10.913947205 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-10 21:44:04.865012909 -0700 PDT [INFO] Removing volume name="BasicTestSuite.TestVmGroupVolumeIsolation_volume_269402" 2017-07-10 21:44:40.603537277 -0700 PDT [INFO] Attaching volume and creating filesystem name="BasicTestSuite.TestVolumeLifecycle_volume_994716" fstype=ext4 2017-07-10 21:44:41.956231955 -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-07-10 21:44:42.867521774 -0700 PDT [INFO] Volume and filesystem created name="BasicTestSuite.TestVolumeLifecycle_volume_994716" fstype=ext4 2017-07-10 21:44:47.143568551 -0700 PDT [INFO] Mounting volume name="BasicTestSuite.TestVolumeLifecycle_volume_994716" 2017-07-10 21:44:47.979605076 -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-07-10 21:44:56.322297107 -0700 PDT [INFO] Unmounting Volume name="BasicTestSuite.TestVolumeLifecycle_volume_994716" 2017-07-10 21:45:04.812789025 -0700 PDT [INFO] Removing volume name="BasicTestSuite.TestVolumeLifecycle_volume_994716" 2017-07-10 21:45:13.386667155 -0700 PDT [INFO] Mounting volume name="vol_access_volume_219786@sharedVmfs-0" 2017-07-10 21:45:13.971674229 -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-07-10 21:45:14.354103041 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_219786@sharedVmfs-0" 2017-07-10 21:45:16.134216326 -0700 PDT [INFO] Mounting volume name="vol_access_volume_219786@sharedVmfs-0" 2017-07-10 21:45:16.763600143 -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-07-10 21:45:17.147466063 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_219786@sharedVmfs-0" 2017-07-10 21:45:26.380701597 -0700 PDT [INFO] Mounting volume name="vol_access_volume_219786@sharedVmfs-0" 2017-07-10 21:45:26.967570409 -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-07-10 21:45:27.264568389 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_219786@sharedVmfs-0" 2017-07-10 21:45:33.480199275 -0700 PDT [INFO] Mounting volume name="vol_access_volume_219786@sharedVmfs-0" 2017-07-10 21:45:34.055596414 -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-07-10 21:45:34.436365024 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_219786@sharedVmfs-0" 2017-07-10 21:45:36.065992277 -0700 PDT [INFO] Mounting volume name="vol_access_volume_219786@sharedVmfs-0" 2017-07-10 21:45:36.671571777 -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-07-10 21:45:37.049166118 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_219786@sharedVmfs-0" 2017-07-10 21:45:49.274272904 -0700 PDT [INFO] Mounting volume name="vol_access_volume_211453@sharedVmfs-0" 2017-07-10 21:45:49.883594784 -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-07-10 21:45:50.195259171 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_211453@sharedVmfs-0" 2017-07-10 21:45:56.175033571 -0700 PDT [INFO] Mounting volume name="vol_access_volume_211453@sharedVmfs-0" 2017-07-10 21:45:57.079554363 -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-07-10 21:45:57.460334585 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_211453@sharedVmfs-0" 2017-07-10 21:45:59.38185363 -0700 PDT [INFO] Mounting volume name="vol_access_volume_211453@sharedVmfs-0" 2017-07-10 21:46:00.059566779 -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-07-10 21:46:00.445633599 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_211453@sharedVmfs-0" 2017-07-10 21:46:08.739526455 -0700 PDT [INFO] Attaching volume and creating filesystem name="thin_volume_509860" fstype=ext4 2017-07-10 21:46:09.411604741 -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-07-10 21:46:10.139583432 -0700 PDT [INFO] Volume and filesystem created name="thin_volume_509860" fstype=ext4 2017-07-10 21:46:11.719487149 -0700 PDT [INFO] Attaching volume and creating filesystem name="zeroedthick_volume_736121" fstype=ext4 2017-07-10 21:46:12.179622315 -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-07-10 21:46:12.831494692 -0700 PDT [INFO] Volume and filesystem created name="zeroedthick_volume_736121" fstype=ext4 2017-07-10 21:46:15.18746867 -0700 PDT [INFO] Attaching volume and creating filesystem name="eagerzeroedthick_volume_210845" fstype=ext4 2017-07-10 21:46:15.847703775 -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-07-10 21:46:16.399525114 -0700 PDT [INFO] Volume and filesystem created name="eagerzeroedthick_volume_210845" fstype=ext4 2017-07-10 21:46:27.163713483 -0700 PDT [INFO] Mounting volume name="thin_volume_509860" 2017-07-10 21:46:27.831614873 -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-07-10 21:46:32.464315271 -0700 PDT [INFO] Unmounting Volume name="thin_volume_509860" 2017-07-10 21:46:34.004656538 -0700 PDT [INFO] Removing volume name="thin_volume_509860" 2017-07-10 21:46:34.388682122 -0700 PDT [INFO] Removing volume name="zeroedthick_volume_736121" 2017-07-10 21:46:34.772428717 -0700 PDT [INFO] Removing volume name="eagerzeroedthick_volume_210845" 2017-07-10 21:50:05.343567185 -0700 PDT [INFO] Attaching volume and creating filesystem fstype=ext4 name="restart_test_volume_224395" 2017-07-10 21:50:05.775839067 -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-07-10 21:50:06.895547483 -0700 PDT [INFO] Volume and filesystem created name="restart_test_volume_224395" fstype=ext4 2017-07-10 21:50:10.855493066 -0700 PDT [INFO] Attaching volume and creating filesystem fstype=ext4 name="restart_test_volume_224395@sharedVmfs-1" 2017-07-10 21:50:11.319577198 -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-07-10 21:50:12.219548208 -0700 PDT [INFO] Volume and filesystem created name="restart_test_volume_224395@sharedVmfs-1" fstype=ext4 2017-07-10 21:50:13.718240284 -0700 PDT [INFO] Mounting volume name="restart_test_volume_224395" 2017-07-10 21:50:14.223679586 -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-07-10 21:50:15.585668514 -0700 PDT [INFO] Mounting volume name="restart_test_volume_224395@sharedVmfs-1" 2017-07-10 21:50:16.203605305 -0700 PDT [INFO] Scan complete device="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0" event="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0": 0x100 == IN_CREATE 2017-07-10 21:50:28.743112469 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_224395@sharedVmfs-1" 2017-07-10 21:50:28.766063591 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_224395" 2017-07-10 21:50:29.707989116 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-10 21:50:31.930717686 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-10 21:50:31.931819637 -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-07-10 21:50:31.931838544 -0700 PDT [INFO] Starting plugin log_level=info config="/etc/docker-volume-vsphere.conf" driver=vsphere 2017-07-10 21:50:31.931855111 -0700 PDT [INFO] Plugin options - port=1019 2017-07-10 21:50:31.931891849 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 21:50:33.932480573 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-10 21:50:33.932575853 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-10 21:50:33.932596118 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-10 21:50:33.932881389 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-10 21:50:33.933907779 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-10 21:50:35.933710325 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 21:50:36.37330328 -0700 PDT [INFO] Mounting volume name="restart_test_volume_224395@sharedVmfs-1" 2017-07-10 21:50:36.46045863 -0700 PDT [INFO] Mounting volume name="restart_test_volume_224395" 2017-07-10 21:50:37.063729304 -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-07-10 21:50:37.934186172 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-10 21:50:37.934229034 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). Attempts left: 20 2017-07-10 21:50:37.93423594 -0700 PDT [INFO] Scheduling again after 4 seconds 2017-07-10 21:50:37.98373012 -0700 PDT [INFO] Scan complete device="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0" event="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0": 0x100 == IN_CREATE 2017-07-10 21:50:41.934429059 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 21:50:41.951134384 -0700 PDT [INFO] Found 2 running or paused containers 2017-07-10 21:50:42.115849194 -0700 PDT [INFO] Discovered 2 volumes in use. 2017-07-10 21:50:42.115882149 -0700 PDT [INFO] Volume name=restart_test_volume_224395@sharedVmfs-0 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0' 2017-07-10 21:50:42.115889164 -0700 PDT [INFO] Volume name=restart_test_volume_224395@sharedVmfs-1 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-10 21:50:42.115903362 -0700 PDT [INFO] Refcounting successfully completed 2017-07-10 21:50:59.909751106 -0700 PDT [INFO] Mounting volume name="restart_test_volume_224395@sharedVmfs-0" 2017-07-10 21:50:59.909869043 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_224395@sharedVmfs-0" refcount=2 2017-07-10 21:51:01.224694597 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_224395@sharedVmfs-1" 2017-07-10 21:51:01.245636211 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_224395" 2017-07-10 21:51:01.275701077 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_224395@sharedVmfs-0" 2017-07-10 21:51:01.639567978 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_224395@sharedVmfs-0" refcount=1 2017-07-10 21:51:03.064726297 -0700 PDT [INFO] Removing volume name="restart_test_volume_224395@sharedVmfs-1" 2017-07-10 21:51:09.956510238 -0700 PDT [INFO] Mounting volume name="restart_test_volume_224395" 2017-07-10 21:51:10.483869834 -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-07-10 21:51:22.029977052 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_224395" 2017-07-10 21:51:22.860180491 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-10 21:51:25.075013131 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-10 21:51:25.07508519 -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-07-10 21:51:25.075095223 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-10 21:51:25.075104727 -0700 PDT [INFO] Plugin options - port=1019 2017-07-10 21:51:25.075130971 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 21:51:27.075474493 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-10 21:51:27.075535103 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-10 21:51:27.075557457 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-10 21:51:27.075794964 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-10 21:51:27.075997183 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-10 21:51:28.764330538 -0700 PDT [INFO] Mounting volume name="restart_test_volume_224395" 2017-07-10 21:51:29.076135908 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 21:51:29.273686821 -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-07-10 21:51:29.533913069 -0700 PDT [INFO] Found 1 running or paused containers 2017-07-10 21:51:30.103907526 -0700 PDT [INFO] Discovered 1 volumes in use. 2017-07-10 21:51:30.10394284 -0700 PDT [INFO] Volume name=restart_test_volume_224395@sharedVmfs-0 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-10 21:51:30.103952912 -0700 PDT [INFO] Refcounting successfully completed 2017-07-10 21:51:51.202824619 -0700 PDT [INFO] Mounting volume name="restart_test_volume_224395" 2017-07-10 21:51:51.299548848 -0700 PDT [INFO] Already mounted, skipping mount. refcount=2 name="restart_test_volume_224395@sharedVmfs-0" 2017-07-10 21:51:53.699479621 -0700 PDT [INFO] Mounting volume name="restart_test_volume_224395@sharedVmfs-0" 2017-07-10 21:51:53.699527333 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_224395@sharedVmfs-0" refcount=3 2017-07-10 21:51:55.020747536 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_224395" 2017-07-10 21:51:55.02079422 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_224395@sharedVmfs-0" refcount=2 2017-07-10 21:51:55.040025158 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_224395@sharedVmfs-0" 2017-07-10 21:51:55.04005647 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_224395@sharedVmfs-0" refcount=1 2017-07-10 21:51:55.094084216 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_224395" 2017-07-10 21:52:00.695156917 -0700 PDT [INFO] Mounting volume name="restart_test_volume_224395" 2017-07-10 21:52:01.189680016 -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-07-10 21:52:10.311318267 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-10 21:52:12.470217599 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-10 21:52:12.473131942 -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-07-10 21:52:12.473175747 -0700 PDT [INFO] Starting plugin config="/etc/docker-volume-vsphere.conf" driver=vsphere log_level=info 2017-07-10 21:52:12.473189672 -0700 PDT [INFO] Plugin options - port=1019 2017-07-10 21:52:12.473200383 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 21:52:12.488423813 -0700 PDT [INFO] Found 1 running or paused containers 2017-07-10 21:52:13.167822588 -0700 PDT [INFO] Discovered 1 volumes in use. 2017-07-10 21:52:13.167854868 -0700 PDT [INFO] Volume name=restart_test_volume_224395@sharedVmfs-0 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-10 21:52:13.16786084 -0700 PDT [INFO] Refcounting successfully completed 2017-07-10 21:52:13.167877197 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-10 21:52:13.168661142 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-10 21:52:24.265181685 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_224395" 2017-07-10 21:52:26.233524163 -0700 PDT [INFO] Mounting volume name="restart_test_volume_224395" 2017-07-10 21:52:26.743683829 -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-07-10 21:52:38.095837572 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_224395" 2017-07-10 21:52:47.307521519 -0700 PDT [INFO] Mounting volume name="restart_test_volume_224395" 2017-07-10 21:52:47.791604747 -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-07-10 21:52:49.137320222 -0700 PDT [INFO] Mounting volume name="restart_test_volume_224395" 2017-07-10 21:52:49.227623938 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_224395@sharedVmfs-0" refcount=2 2017-07-10 21:53:00.891971088 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_224395" 2017-07-10 21:53:00.892008963 -0700 PDT [INFO] Still in use, skipping unmount request. refcount=1 name="restart_test_volume_224395@sharedVmfs-0" 2017-07-10 21:53:00.952012768 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_224395" 2017-07-10 21:53:05.092012846 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-10 21:53:07.302374282 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-10 21:53:07.3024305 -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-07-10 21:53:07.30243958 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-10 21:53:07.302448537 -0700 PDT [INFO] Plugin options - port=1019 2017-07-10 21:53:07.302463905 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 21:53:09.30293757 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-10 21:53:09.302982036 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-10 21:53:09.302997447 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-10 21:53:09.30389522 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-10 21:53:09.304022302 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-10 21:53:11.304275124 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 21:53:13.305001321 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-10 21:53:13.305031959 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). Attempts left: 20 2017-07-10 21:53:13.305041884 -0700 PDT [INFO] Scheduling again after 4 seconds 2017-07-10 21:53:13.576630717 -0700 PDT [INFO] Mounting volume name="restart_test_volume_224395" 2017-07-10 21:53:14.071796128 -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-07-10 21:53:14.264119169 -0700 PDT [INFO] Mounting volume name="restart_test_volume_224395" 2017-07-10 21:53:14.391884774 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_224395@sharedVmfs-0" 2017-07-10 21:53:17.305229977 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 21:53:17.317060246 -0700 PDT [INFO] Found 2 running or paused containers 2017-07-10 21:53:17.684834546 -0700 PDT [INFO] Discovered 1 volumes in use. 2017-07-10 21:53:17.684869247 -0700 PDT [INFO] Volume name=restart_test_volume_224395@sharedVmfs-0 count=2 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-10 21:53:17.684880517 -0700 PDT [INFO] Refcounting successfully completed 2017-07-10 21:53:42.042671694 -0700 PDT [INFO] Mounting volume name="restart_test_volume_224395" 2017-07-10 21:53:42.13168914 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_224395@sharedVmfs-0" refcount=3 2017-07-10 21:53:43.63740012 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_224395" 2017-07-10 21:53:43.637436226 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_224395@sharedVmfs-0" refcount=2 2017-07-10 21:53:43.649883899 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_224395" 2017-07-10 21:53:43.649907301 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_224395@sharedVmfs-0" refcount=1 2017-07-10 21:53:43.717334011 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_224395" 2017-07-10 21:53:56.160663162 -0700 PDT [INFO] Mounting volume name="restart_test_volume_224395" 2017-07-10 21:53:56.643597633 -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-07-10 21:54:14.079251822 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_224395" 2017-07-10 21:54:14.820035479 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-10 21:54:17.024443228 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-10 21:54:17.024549752 -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-07-10 21:54:17.024567286 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-10 21:54:17.024578426 -0700 PDT [INFO] Plugin options - port=1019 2017-07-10 21:54:17.024636995 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 21:54:19.02514497 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-10 21:54:19.025218611 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-10 21:54:19.025240223 -0700 PDT [INFO] Docker VMDK plugin started mock_esx=false version="vSphere Volume Driver v0.5" port=1019 2017-07-10 21:54:19.025326022 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-10 21:54:19.026236875 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-10 21:54:21.026392201 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 21:54:21.044103248 -0700 PDT [INFO] Found 0 running or paused containers 2017-07-10 21:54:21.044671888 -0700 PDT [INFO] Discovered 0 volumes in use. 2017-07-10 21:54:21.044692581 -0700 PDT [INFO] Refcounting successfully completed 2017-07-10 21:54:56.396752065 -0700 PDT [INFO] Mounting volume name="restart_test_volume_224395" 2017-07-10 21:54:56.891688516 -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-07-10 21:54:58.413282473 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_224395" 2017-07-10 21:55:01.14887569 -0700 PDT [INFO] Removing volume name="restart_test_volume_224395" 2017-07-10 21:55:21.91957233 -0700 PDT [INFO] Attaching volume and creating filesystem name="basicVGTest_volume_940976" fstype=ext4 2017-07-10 21:55:22.355583804 -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-07-10 21:55:22.931521427 -0700 PDT [INFO] Volume and filesystem created name="basicVGTest_volume_940976" fstype=ext4 2017-07-10 21:55:45.408688588 -0700 PDT [INFO] Removing volume name="basicVGTest_volume_940976" 2017-07-10 21:58:56.824953115 -0700 PDT [INFO] Removing volume name="VmGroupTest.TestVmGroupVolumeAccessAcrossVmGroups_volume_770864" 2017-07-10 22:39:47.527650527 -0700 PDT [INFO] Attaching volume and creating filesystem name="thin_volume_781249" fstype=ext4 2017-07-10 22:39:48.023933645 -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-07-10 22:39:48.647586827 -0700 PDT [INFO] Volume and filesystem created name="thin_volume_781249" fstype=ext4 2017-07-10 22:39:50.17150786 -0700 PDT [INFO] Attaching volume and creating filesystem name="zeroedthick_volume_468225" fstype=ext4 2017-07-10 22:39:50.647631569 -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-07-10 22:39:51.24353535 -0700 PDT [INFO] Volume and filesystem created name="zeroedthick_volume_468225" fstype=ext4 2017-07-10 22:39:53.167502289 -0700 PDT [INFO] Attaching volume and creating filesystem name="eagerzeroedthick_volume_735181" fstype=ext4 2017-07-10 22:39:54.087637097 -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-07-10 22:39:54.615522171 -0700 PDT [INFO] Volume and filesystem created name="eagerzeroedthick_volume_735181" fstype=ext4 2017-07-10 22:40:06.05072373 -0700 PDT [INFO] Mounting volume name="thin_volume_781249" 2017-07-10 22:40:06.691600419 -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-07-10 22:40:11.561848516 -0700 PDT [INFO] Unmounting Volume name="thin_volume_781249" 2017-07-10 22:40:13.712577905 -0700 PDT [INFO] Removing volume name="thin_volume_781249" 2017-07-10 22:40:14.100478245 -0700 PDT [INFO] Removing volume name="zeroedthick_volume_468225" 2017-07-10 22:40:14.512662791 -0700 PDT [INFO] Removing volume name="eagerzeroedthick_volume_735181" 2017-07-10 22:43:33.395987259 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-10 22:48:07.493808482 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-10 22:48:07.493919034 -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-07-10 22:48:07.493931209 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-10 22:48:07.493988474 -0700 PDT [INFO] Plugin options - port=1019 2017-07-10 22:48:07.494001117 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 22:48:07.514551009 -0700 PDT [INFO] Found 0 running or paused containers 2017-07-10 22:48:07.514889549 -0700 PDT [INFO] Discovered 0 volumes in use. 2017-07-10 22:48:07.514904816 -0700 PDT [INFO] Refcounting successfully completed 2017-07-10 22:48:07.51492033 -0700 PDT [INFO] Docker VMDK plugin started mock_esx=false version="vSphere Volume Driver v0.5" port=1019 2017-07-10 22:48:07.51542845 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-10 22:51:54.526093358 -0700 PDT [INFO] Removing volume name="BasicTestSuite.TestVmGroupVolumeIsolation_volume_876734" 2017-07-10 22:52:26.139569527 -0700 PDT [INFO] Attaching volume and creating filesystem name="BasicTestSuite.TestVolumeLifecycle_volume_905752" fstype=ext4 2017-07-10 22:52:26.592233543 -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-07-10 22:52:27.283528717 -0700 PDT [INFO] Volume and filesystem created fstype=ext4 name="BasicTestSuite.TestVolumeLifecycle_volume_905752" 2017-07-10 22:52:30.252193749 -0700 PDT [INFO] Mounting volume name="BasicTestSuite.TestVolumeLifecycle_volume_905752" 2017-07-10 22:52:30.835595645 -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-07-10 22:52:39.159301332 -0700 PDT [INFO] Unmounting Volume name="BasicTestSuite.TestVolumeLifecycle_volume_905752" 2017-07-10 22:52:47.004628536 -0700 PDT [INFO] Removing volume name="BasicTestSuite.TestVolumeLifecycle_volume_905752" 2017-07-10 22:52:55.193080115 -0700 PDT [INFO] Mounting volume name="vol_access_volume_717045@sharedVmfs-0" 2017-07-10 22:52:55.791584752 -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-07-10 22:52:56.171645969 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_717045@sharedVmfs-0" 2017-07-10 22:52:57.760878335 -0700 PDT [INFO] Mounting volume name="vol_access_volume_717045@sharedVmfs-0" 2017-07-10 22:52:58.367553691 -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-07-10 22:52:58.768042112 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_717045@sharedVmfs-0" 2017-07-10 22:53:07.435016326 -0700 PDT [INFO] Mounting volume name="vol_access_volume_717045@sharedVmfs-0" 2017-07-10 22:53:08.035573468 -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-07-10 22:53:08.377950124 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_717045@sharedVmfs-0" 2017-07-10 22:53:14.341008255 -0700 PDT [INFO] Mounting volume name="vol_access_volume_717045@sharedVmfs-0" 2017-07-10 22:53:14.935673681 -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-07-10 22:53:15.343853815 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_717045@sharedVmfs-0" 2017-07-10 22:53:16.873094619 -0700 PDT [INFO] Mounting volume name="vol_access_volume_717045@sharedVmfs-0" 2017-07-10 22:53:17.479555527 -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-07-10 22:53:17.860430164 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_717045@sharedVmfs-0" 2017-07-10 22:53:28.642418895 -0700 PDT [INFO] Mounting volume name="vol_access_volume_814257@sharedVmfs-0" 2017-07-10 22:53:29.195557633 -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-07-10 22:53:29.536106859 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_814257@sharedVmfs-0" 2017-07-10 22:53:35.602079098 -0700 PDT [INFO] Mounting volume name="vol_access_volume_814257@sharedVmfs-0" 2017-07-10 22:53:36.159624419 -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-07-10 22:53:36.552396575 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_814257@sharedVmfs-0" 2017-07-10 22:53:38.090923818 -0700 PDT [INFO] Mounting volume name="vol_access_volume_814257@sharedVmfs-0" 2017-07-10 22:53:38.65160647 -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-07-10 22:53:39.028163251 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_814257@sharedVmfs-0" 2017-07-10 22:53:44.94366401 -0700 PDT [INFO] Attaching volume and creating filesystem fstype=ext4 name="thin_volume_1082921" 2017-07-10 22:53:45.395759735 -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-07-10 22:53:46.179511239 -0700 PDT [INFO] Volume and filesystem created name="thin_volume_1082921" fstype=ext4 2017-07-10 22:53:47.663485623 -0700 PDT [INFO] Attaching volume and creating filesystem name="zeroedthick_volume_689468" fstype=ext4 2017-07-10 22:53:48.111678868 -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-07-10 22:53:48.635499252 -0700 PDT [INFO] Volume and filesystem created name="zeroedthick_volume_689468" fstype=ext4 2017-07-10 22:53:50.415517326 -0700 PDT [INFO] Attaching volume and creating filesystem name="eagerzeroedthick_volume_993329" fstype=ext4 2017-07-10 22:53:50.879590615 -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-07-10 22:53:51.503632657 -0700 PDT [INFO] Volume and filesystem created name="eagerzeroedthick_volume_993329" fstype=ext4 2017-07-10 22:54:01.550214468 -0700 PDT [INFO] Mounting volume name="thin_volume_1082921" 2017-07-10 22:54:02.139632256 -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-07-10 22:54:06.436254843 -0700 PDT [INFO] Unmounting Volume name="thin_volume_1082921" 2017-07-10 22:54:08.120415443 -0700 PDT [INFO] Removing volume name="thin_volume_1082921" 2017-07-10 22:54:08.484391347 -0700 PDT [INFO] Removing volume name="zeroedthick_volume_689468" 2017-07-10 22:54:08.856352375 -0700 PDT [INFO] Removing volume name="eagerzeroedthick_volume_993329" 2017-07-10 22:57:36.251691057 -0700 PDT [INFO] Attaching volume and creating filesystem name="restart_test_volume_766287" fstype=ext4 2017-07-10 22:57:36.651718984 -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-07-10 22:57:37.555601283 -0700 PDT [INFO] Volume and filesystem created name="restart_test_volume_766287" fstype=ext4 2017-07-10 22:57:41.719520018 -0700 PDT [INFO] Attaching volume and creating filesystem fstype=ext4 name="restart_test_volume_766287@sharedVmfs-1" 2017-07-10 22:57:42.167584131 -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-07-10 22:57:42.863602081 -0700 PDT [INFO] Volume and filesystem created name="restart_test_volume_766287@sharedVmfs-1" fstype=ext4 2017-07-10 22:57:44.458684468 -0700 PDT [INFO] Mounting volume name="restart_test_volume_766287" 2017-07-10 22:57:44.991571271 -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-07-10 22:57:46.310756514 -0700 PDT [INFO] Mounting volume name="restart_test_volume_766287@sharedVmfs-1" 2017-07-10 22:57:46.931619587 -0700 PDT [INFO] Scan complete device="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0" event="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0": 0x100 == IN_CREATE 2017-07-10 22:57:59.240524969 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_766287@sharedVmfs-1" 2017-07-10 22:57:59.250749319 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_766287" 2017-07-10 22:58:00.256374163 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-10 22:58:02.476276605 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-10 22:58:02.476351298 -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-07-10 22:58:02.476408524 -0700 PDT [INFO] Starting plugin log_level=info config="/etc/docker-volume-vsphere.conf" driver=vsphere 2017-07-10 22:58:02.476421999 -0700 PDT [INFO] Plugin options - port=1019 2017-07-10 22:58:02.476453135 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 22:58:04.477269959 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-10 22:58:04.477321321 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-10 22:58:04.477375199 -0700 PDT [INFO] Docker VMDK plugin started port=1019 mock_esx=false version="vSphere Volume Driver v0.5" 2017-07-10 22:58:04.477625551 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-10 22:58:04.477781882 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-10 22:58:06.478816606 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 22:58:07.032498769 -0700 PDT [INFO] Mounting volume name="restart_test_volume_766287@sharedVmfs-1" 2017-07-10 22:58:07.124104494 -0700 PDT [INFO] Mounting volume name="restart_test_volume_766287" 2017-07-10 22:58:07.739814793 -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-07-10 22:58:08.463589668 -0700 PDT [INFO] Scan complete device="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0" event="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0": 0x100 == IN_CREATE 2017-07-10 22:58:08.47900374 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-10 22:58:08.479106522 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). Attempts left: 20 2017-07-10 22:58:08.479115328 -0700 PDT [INFO] Scheduling again after 4 seconds 2017-07-10 22:58:12.479431285 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 22:58:12.49475543 -0700 PDT [INFO] Found 2 running or paused containers 2017-07-10 22:58:12.627817745 -0700 PDT [INFO] Discovered 2 volumes in use. 2017-07-10 22:58:12.627851488 -0700 PDT [INFO] Volume name=restart_test_volume_766287@sharedVmfs-1 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-10 22:58:12.62786454 -0700 PDT [INFO] Volume name=restart_test_volume_766287@sharedVmfs-0 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0' 2017-07-10 22:58:12.6278749 -0700 PDT [INFO] Refcounting successfully completed 2017-07-10 22:58:30.149229159 -0700 PDT [INFO] Mounting volume name="restart_test_volume_766287@sharedVmfs-0" 2017-07-10 22:58:30.149276722 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_766287@sharedVmfs-0" refcount=2 2017-07-10 22:58:31.521765329 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_766287@sharedVmfs-0" 2017-07-10 22:58:31.521807383 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_766287@sharedVmfs-0" refcount=1 2017-07-10 22:58:31.539441908 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_766287@sharedVmfs-1" 2017-07-10 22:58:31.604749571 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_766287" 2017-07-10 22:58:33.444683499 -0700 PDT [INFO] Removing volume name="restart_test_volume_766287@sharedVmfs-1" 2017-07-10 22:58:38.854018261 -0700 PDT [INFO] Mounting volume name="restart_test_volume_766287" 2017-07-10 22:58:39.339629522 -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-07-10 22:58:50.683046159 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_766287" 2017-07-10 22:58:51.46804825 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-10 22:58:53.681942207 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-10 22:58:53.683675293 -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-07-10 22:58:53.683730742 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-10 22:58:53.683746287 -0700 PDT [INFO] Plugin options - port=1019 2017-07-10 22:58:53.683758086 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 22:58:55.684299413 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-10 22:58:55.684524479 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-10 22:58:55.68481039 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-10 22:58:55.684974294 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-10 22:58:55.685641679 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-10 22:58:57.644457478 -0700 PDT [INFO] Mounting volume name="restart_test_volume_766287" 2017-07-10 22:58:57.686811957 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 22:58:58.579852926 -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-07-10 22:58:58.857845138 -0700 PDT [INFO] Found 1 running or paused containers 2017-07-10 22:58:58.96400871 -0700 PDT [INFO] Discovered 1 volumes in use. 2017-07-10 22:58:58.964042741 -0700 PDT [INFO] Volume name=restart_test_volume_766287@sharedVmfs-0 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-10 22:58:58.964049598 -0700 PDT [INFO] Refcounting successfully completed 2017-07-10 22:59:20.603122932 -0700 PDT [INFO] Mounting volume name="restart_test_volume_766287" 2017-07-10 22:59:20.695633431 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_766287@sharedVmfs-0" refcount=2 2017-07-10 22:59:23.11759134 -0700 PDT [INFO] Mounting volume name="restart_test_volume_766287@sharedVmfs-0" 2017-07-10 22:59:23.117648055 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_766287@sharedVmfs-0" refcount=3 2017-07-10 22:59:24.387360209 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_766287@sharedVmfs-0" 2017-07-10 22:59:24.387445129 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_766287@sharedVmfs-0" refcount=2 2017-07-10 22:59:24.406498133 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_766287" 2017-07-10 22:59:24.406521884 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_766287@sharedVmfs-0" refcount=1 2017-07-10 22:59:24.47000929 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_766287" 2017-07-10 22:59:29.550474648 -0700 PDT [INFO] Mounting volume name="restart_test_volume_766287" 2017-07-10 22:59:30.039422314 -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-07-10 22:59:38.283266408 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-10 22:59:40.442551484 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-10 22:59:40.444496697 -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-07-10 22:59:40.444519257 -0700 PDT [INFO] Starting plugin log_level=info config="/etc/docker-volume-vsphere.conf" driver=vsphere 2017-07-10 22:59:40.444531031 -0700 PDT [INFO] Plugin options - port=1019 2017-07-10 22:59:40.444542514 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 22:59:40.458748286 -0700 PDT [INFO] Found 1 running or paused containers 2017-07-10 22:59:41.140010367 -0700 PDT [INFO] Discovered 1 volumes in use. 2017-07-10 22:59:41.140043406 -0700 PDT [INFO] Volume name=restart_test_volume_766287@sharedVmfs-0 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-10 22:59:41.14004948 -0700 PDT [INFO] Refcounting successfully completed 2017-07-10 22:59:41.140084077 -0700 PDT [INFO] Docker VMDK plugin started mock_esx=false version="vSphere Volume Driver v0.5" port=1019 2017-07-10 22:59:41.14031391 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-10 22:59:52.231880215 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_766287" 2017-07-10 22:59:54.001854724 -0700 PDT [INFO] Mounting volume name="restart_test_volume_766287" 2017-07-10 22:59:54.519773684 -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-07-10 23:00:05.818135701 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_766287" 2017-07-10 23:00:14.529842748 -0700 PDT [INFO] Mounting volume name="restart_test_volume_766287" 2017-07-10 23:00:15.047614832 -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-07-10 23:00:16.322225051 -0700 PDT [INFO] Mounting volume name="restart_test_volume_766287" 2017-07-10 23:00:16.415543966 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_766287@sharedVmfs-0" refcount=2 2017-07-10 23:00:27.68878071 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_766287" 2017-07-10 23:00:27.688817029 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_766287@sharedVmfs-0" refcount=1 2017-07-10 23:00:27.702824296 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_766287" 2017-07-10 23:00:28.491996969 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-10 23:00:30.715461169 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-10 23:00:30.71580715 -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-07-10 23:00:30.715848914 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-10 23:00:30.715870785 -0700 PDT [INFO] Plugin options - port=1019 2017-07-10 23:00:30.715914857 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 23:00:32.716485033 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-10 23:00:32.716549409 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-10 23:00:32.716562577 -0700 PDT [INFO] Docker VMDK plugin started port=1019 mock_esx=false version="vSphere Volume Driver v0.5" 2017-07-10 23:00:32.716914608 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-10 23:00:32.716992513 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-10 23:00:34.717392814 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 23:00:35.316173923 -0700 PDT [INFO] Mounting volume name="restart_test_volume_766287" 2017-07-10 23:00:35.807710255 -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-07-10 23:00:36.216151669 -0700 PDT [INFO] Mounting volume name="restart_test_volume_766287" 2017-07-10 23:00:36.327801464 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_766287@sharedVmfs-0" 2017-07-10 23:00:36.53728261 -0700 PDT [INFO] Found 2 running or paused containers 2017-07-10 23:00:36.640969753 -0700 PDT [INFO] Discovered 1 volumes in use. 2017-07-10 23:00:36.641004132 -0700 PDT [INFO] Volume name=restart_test_volume_766287@sharedVmfs-0 count=2 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-10 23:00:36.641010355 -0700 PDT [INFO] Refcounting successfully completed 2017-07-10 23:01:03.274764809 -0700 PDT [INFO] Mounting volume name="restart_test_volume_766287" 2017-07-10 23:01:03.371632714 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_766287@sharedVmfs-0" refcount=3 2017-07-10 23:01:04.693511054 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_766287" 2017-07-10 23:01:04.693583198 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_766287@sharedVmfs-0" refcount=2 2017-07-10 23:01:04.709183051 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_766287" 2017-07-10 23:01:04.709208351 -0700 PDT [INFO] Still in use, skipping unmount request. refcount=1 name="restart_test_volume_766287@sharedVmfs-0" 2017-07-10 23:01:04.72213143 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_766287" 2017-07-10 23:01:16.721797279 -0700 PDT [INFO] Mounting volume name="restart_test_volume_766287" 2017-07-10 23:01:17.22762006 -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-07-10 23:01:34.385130134 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_766287" 2017-07-10 23:01:35.160189639 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-10 23:01:37.381721701 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-10 23:01:37.381783173 -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-07-10 23:01:37.381797796 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-10 23:01:37.381809144 -0700 PDT [INFO] Plugin options - port=1019 2017-07-10 23:01:37.381819152 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 23:01:39.38238608 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-10 23:01:39.382544843 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-10 23:01:39.382570084 -0700 PDT [INFO] Docker VMDK plugin started mock_esx=false version="vSphere Volume Driver v0.5" port=1019 2017-07-10 23:01:39.382653378 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-10 23:01:39.382923862 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-10 23:01:41.382925992 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-10 23:01:41.412593532 -0700 PDT [INFO] Found 0 running or paused containers 2017-07-10 23:01:41.412786389 -0700 PDT [INFO] Discovered 0 volumes in use. 2017-07-10 23:01:41.412795896 -0700 PDT [INFO] Refcounting successfully completed 2017-07-10 23:02:16.972939497 -0700 PDT [INFO] Mounting volume name="restart_test_volume_766287" 2017-07-10 23:02:17.495711555 -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-07-10 23:02:18.984317671 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_766287" 2017-07-10 23:02:21.673484347 -0700 PDT [INFO] Removing volume name="restart_test_volume_766287" 2017-07-10 23:02:40.575518202 -0700 PDT [INFO] Attaching volume and creating filesystem name="basicVGTest_volume_935100" fstype=ext4 2017-07-10 23:02:40.995577883 -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-07-10 23:02:41.54751097 -0700 PDT [INFO] Volume and filesystem created name="basicVGTest_volume_935100" fstype=ext4 2017-07-10 23:03:00.333332477 -0700 PDT [INFO] Removing volume name="basicVGTest_volume_935100" 2017-07-10 23:06:07.8755805 -0700 PDT [INFO] Removing volume name="VmGroupTest.TestVmGroupVolumeAccessAcrossVmGroups_volume_228828" 2017-07-10 23:09:22.847627629 -0700 PDT [INFO] Mounting volume name="vmlistener_test_volume_127228" 2017-07-10 23:09:23.399896049 -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-07-10 23:09:30.327956305 -0700 PDT [INFO] Unmounting Volume name="vmlistener_test_volume_127228" 2017-07-10 23:10:44.273738541 -0700 PDT [INFO] Mounting volume name="vmlistener_test_volume_526564@vsanDatastore" 2017-07-10 23:10:45.06380296 -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-07-10 23:10:51.987897802 -0700 PDT [INFO] Unmounting Volume name="vmlistener_test_volume_526564@vsanDatastore" 2017-07-10 23:22:17.047789675 -0700 PDT [INFO] Attaching volume and creating filesystem name=volTestP10 fstype=ext4 2017-07-10 23:22:18.351807247 -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-07-10 23:22:19.155589875 -0700 PDT [INFO] Volume and filesystem created name=volTestP10 fstype=ext4 2017-07-10 23:22:19.265602922 -0700 PDT [INFO] Removing volume name=volTestP10 2017-07-10 23:22:20.371502488 -0700 PDT [INFO] Attaching volume and creating filesystem name=volTestP11 fstype=ext4 2017-07-10 23:22:20.911622519 -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-07-10 23:22:21.719536926 -0700 PDT [INFO] Volume and filesystem created name=volTestP11 fstype=ext4 2017-07-10 23:22:21.857351967 -0700 PDT [INFO] Removing volume name=volTestP11 2017-07-10 23:22:23.37150781 -0700 PDT [INFO] Attaching volume and creating filesystem name=volTestP12 fstype=ext4 2017-07-10 23:22:23.963575195 -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-07-10 23:22:25.419642896 -0700 PDT [INFO] Volume and filesystem created name=volTestP12 fstype=ext4 2017-07-10 23:22:25.568707614 -0700 PDT [INFO] Removing volume name=volTestP12 2017-07-10 23:22:36.869475363 -0700 PDT [INFO] Removing volume name=volTestPClone-clone10 2017-07-10 23:22:39.384839758 -0700 PDT [INFO] Removing volume name=volTestPClone-clone11 2017-07-11 11:18:04.073906352 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-11 11:18:43.381408625 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-11 11:18:43.381572991 -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-07-11 11:18:43.381582879 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-11 11:18:43.381591808 -0700 PDT [INFO] Plugin options - port=1019 2017-07-11 11:18:43.381603071 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 11:18:43.41192255 -0700 PDT [INFO] Found 0 running or paused containers 2017-07-11 11:18:43.412637414 -0700 PDT [INFO] Discovered 0 volumes in use. 2017-07-11 11:18:43.412661912 -0700 PDT [INFO] Refcounting successfully completed 2017-07-11 11:18:43.412676221 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-11 11:18:43.413042242 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-11 11:34:15.571592735 -0700 PDT [INFO] Attaching volume and creating filesystem name="basicVGTest_volume_885085" fstype=ext4 2017-07-11 11:34:16.028070908 -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-07-11 11:34:16.63154565 -0700 PDT [INFO] Volume and filesystem created fstype=ext4 name="basicVGTest_volume_885085" 2017-07-11 11:34:28.144679219 -0700 PDT [INFO] Removing volume name="basicVGTest_volume_885085" 2017-07-11 11:39:13.51136283 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-11 11:39:38.808197431 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-11 11:39:38.808291324 -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-07-11 11:39:38.808301205 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-11 11:39:38.808312964 -0700 PDT [INFO] Plugin options - port=1019 2017-07-11 11:39:38.808354459 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 11:39:38.828296723 -0700 PDT [INFO] Found 0 running or paused containers 2017-07-11 11:39:38.828566345 -0700 PDT [INFO] Discovered 0 volumes in use. 2017-07-11 11:39:38.828582756 -0700 PDT [INFO] Refcounting successfully completed 2017-07-11 11:39:38.828594212 -0700 PDT [INFO] Docker VMDK plugin started mock_esx=false version="vSphere Volume Driver v0.5" port=1019 2017-07-11 11:39:38.829165354 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-11 11:41:04.702423909 -0700 PDT [INFO] Removing volume name="BasicTestSuite.TestVmGroupVolumeIsolation_volume_1080244" 2017-07-11 11:41:28.815501008 -0700 PDT [INFO] Attaching volume and creating filesystem name="BasicTestSuite.TestVolumeLifecycle_volume_267029" fstype=ext4 2017-07-11 11:41:29.635772925 -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-07-11 11:41:30.21953498 -0700 PDT [INFO] Volume and filesystem created fstype=ext4 name="BasicTestSuite.TestVolumeLifecycle_volume_267029" 2017-07-11 11:41:31.590950164 -0700 PDT [INFO] Mounting volume name="BasicTestSuite.TestVolumeLifecycle_volume_267029" 2017-07-11 11:41:32.199615699 -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-07-11 11:41:37.376380822 -0700 PDT [INFO] Unmounting Volume name="BasicTestSuite.TestVolumeLifecycle_volume_267029" 2017-07-11 11:41:43.188683178 -0700 PDT [INFO] Removing volume name="BasicTestSuite.TestVolumeLifecycle_volume_267029" 2017-07-11 11:41:49.424717071 -0700 PDT [INFO] Mounting volume name="vol_access_volume_837030@sharedVmfs-0" 2017-07-11 11:41:50.119874348 -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-07-11 11:41:50.504944402 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_837030@sharedVmfs-0" 2017-07-11 11:41:51.842519295 -0700 PDT [INFO] Mounting volume name="vol_access_volume_837030@sharedVmfs-0" 2017-07-11 11:41:52.443588757 -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-07-11 11:41:52.824264783 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_837030@sharedVmfs-0" 2017-07-11 11:42:00.115933832 -0700 PDT [INFO] Mounting volume name="vol_access_volume_837030@sharedVmfs-0" 2017-07-11 11:42:00.763568668 -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-07-11 11:42:01.092961529 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_837030@sharedVmfs-0" 2017-07-11 11:42:06.396780169 -0700 PDT [INFO] Mounting volume name="vol_access_volume_837030@sharedVmfs-0" 2017-07-11 11:42:07.035714204 -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-07-11 11:42:07.445692055 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_837030@sharedVmfs-0" 2017-07-11 11:42:08.50567764 -0700 PDT [INFO] Mounting volume name="vol_access_volume_837030@sharedVmfs-0" 2017-07-11 11:42:09.143617594 -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-07-11 11:42:09.581782761 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_837030@sharedVmfs-0" 2017-07-11 11:42:18.744431798 -0700 PDT [INFO] Mounting volume name="vol_access_volume_237816@sharedVmfs-0" 2017-07-11 11:42:19.763558971 -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-07-11 11:42:20.076068024 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_237816@sharedVmfs-0" 2017-07-11 11:42:24.348803034 -0700 PDT [INFO] Mounting volume name="vol_access_volume_237816@sharedVmfs-0" 2017-07-11 11:42:24.935595696 -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-07-11 11:42:25.327893213 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_237816@sharedVmfs-0" 2017-07-11 11:42:26.656458779 -0700 PDT [INFO] Mounting volume name="vol_access_volume_237816@sharedVmfs-0" 2017-07-11 11:42:27.455852543 -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-07-11 11:42:27.848028127 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_237816@sharedVmfs-0" 2017-07-11 11:42:32.771508668 -0700 PDT [INFO] Attaching volume and creating filesystem name="thin_volume_156553" fstype=ext4 2017-07-11 11:42:33.259592207 -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-07-11 11:42:33.827794067 -0700 PDT [INFO] Volume and filesystem created name="thin_volume_156553" fstype=ext4 2017-07-11 11:42:34.803476474 -0700 PDT [INFO] Attaching volume and creating filesystem fstype=ext4 name="zeroedthick_volume_556606" 2017-07-11 11:42:35.283586571 -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-07-11 11:42:35.863540119 -0700 PDT [INFO] Volume and filesystem created fstype=ext4 name="zeroedthick_volume_556606" 2017-07-11 11:42:37.023488011 -0700 PDT [INFO] Attaching volume and creating filesystem fstype=ext4 name="eagerzeroedthick_volume_241267" 2017-07-11 11:42:37.959582886 -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-07-11 11:42:38.50351402 -0700 PDT [INFO] Volume and filesystem created name="eagerzeroedthick_volume_241267" fstype=ext4 2017-07-11 11:42:44.942445757 -0700 PDT [INFO] Mounting volume name="thin_volume_156553" 2017-07-11 11:42:45.555583522 -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-07-11 11:42:48.169622451 -0700 PDT [INFO] Unmounting Volume name="thin_volume_156553" 2017-07-11 11:42:49.184549841 -0700 PDT [INFO] Removing volume name="thin_volume_156553" 2017-07-11 11:42:49.600637092 -0700 PDT [INFO] Removing volume name="zeroedthick_volume_556606" 2017-07-11 11:42:50.009036462 -0700 PDT [INFO] Removing volume name="eagerzeroedthick_volume_241267" 2017-07-11 11:43:59.603534768 -0700 PDT [INFO] Attaching volume and creating filesystem fstype=ext4 name="restart_test_volume_918109" 2017-07-11 11:44:00.099583807 -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-07-11 11:44:00.711506888 -0700 PDT [INFO] Volume and filesystem created name="restart_test_volume_918109" fstype=ext4 2017-07-11 11:44:03.463497243 -0700 PDT [INFO] Attaching volume and creating filesystem name="restart_test_volume_918109@sharedVmfs-1" fstype=ext4 2017-07-11 11:44:03.995596432 -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-07-11 11:44:04.619557291 -0700 PDT [INFO] Volume and filesystem created name="restart_test_volume_918109@sharedVmfs-1" fstype=ext4 2017-07-11 11:44:05.39548029 -0700 PDT [INFO] Mounting volume name="restart_test_volume_918109" 2017-07-11 11:44:06.015663731 -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-07-11 11:44:07.563092301 -0700 PDT [INFO] Mounting volume name="restart_test_volume_918109@sharedVmfs-1" 2017-07-11 11:44:08.207622737 -0700 PDT [INFO] Scan complete event="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0": 0x100 == IN_CREATE device="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0" 2017-07-11 11:44:19.719497204 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_918109" 2017-07-11 11:44:19.740518425 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_918109@sharedVmfs-1" 2017-07-11 11:44:20.795949676 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-11 11:44:23.014129361 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-11 11:44:23.014196838 -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-07-11 11:44:23.014211896 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-11 11:44:23.014223694 -0700 PDT [INFO] Plugin options - port=1019 2017-07-11 11:44:23.014243451 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 11:44:25.014611927 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-11 11:44:25.014668242 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-11 11:44:25.014690772 -0700 PDT [INFO] Docker VMDK plugin started mock_esx=false version="vSphere Volume Driver v0.5" port=1019 2017-07-11 11:44:25.015039977 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-11 11:44:25.015108501 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-11 11:44:27.015510699 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 11:44:28.636662608 -0700 PDT [INFO] Mounting volume name="restart_test_volume_918109@sharedVmfs-1" 2017-07-11 11:44:28.788402964 -0700 PDT [INFO] Mounting volume name="restart_test_volume_918109" 2017-07-11 11:44:29.015804009 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-11 11:44:29.015844004 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). Attempts left: 20 2017-07-11 11:44:29.015851982 -0700 PDT [INFO] Scheduling again after 4 seconds 2017-07-11 11:44:29.403836593 -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-07-11 11:44:30.255592186 -0700 PDT [INFO] Scan complete device="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0" event="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0": 0x100 == IN_CREATE 2017-07-11 11:44:33.016448024 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 11:44:33.028587516 -0700 PDT [INFO] Found 2 running or paused containers 2017-07-11 11:44:33.247823962 -0700 PDT [INFO] Discovered 2 volumes in use. 2017-07-11 11:44:33.247856416 -0700 PDT [INFO] Volume name=restart_test_volume_918109@sharedVmfs-1 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-11 11:44:33.247863234 -0700 PDT [INFO] Volume name=restart_test_volume_918109@sharedVmfs-0 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0' 2017-07-11 11:44:33.24786824 -0700 PDT [INFO] Refcounting successfully completed 2017-07-11 11:44:51.518766545 -0700 PDT [INFO] Mounting volume name="restart_test_volume_918109@sharedVmfs-0" 2017-07-11 11:44:51.518802811 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_918109@sharedVmfs-0" refcount=2 2017-07-11 11:44:52.389165156 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_918109" 2017-07-11 11:44:52.389202471 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_918109@sharedVmfs-0" refcount=1 2017-07-11 11:44:52.461914071 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_918109@sharedVmfs-1" 2017-07-11 11:44:52.48528172 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_918109@sharedVmfs-0" 2017-07-11 11:44:53.813026849 -0700 PDT [INFO] Removing volume name="restart_test_volume_918109@sharedVmfs-1" 2017-07-11 11:44:57.475663846 -0700 PDT [INFO] Mounting volume name="restart_test_volume_918109" 2017-07-11 11:44:58.231630685 -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-07-11 11:45:09.087795403 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_918109" 2017-07-11 11:45:09.975791211 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-11 11:45:12.175440934 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-11 11:45:12.175500809 -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-07-11 11:45:12.175516234 -0700 PDT [INFO] Starting plugin config="/etc/docker-volume-vsphere.conf" driver=vsphere log_level=info 2017-07-11 11:45:12.175534866 -0700 PDT [INFO] Plugin options - port=1019 2017-07-11 11:45:12.175545599 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 11:45:14.17612523 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-11 11:45:14.176206363 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-11 11:45:14.176228573 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-11 11:45:14.176405738 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-11 11:45:14.17658654 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-11 11:45:16.17658635 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 11:45:17.45217296 -0700 PDT [INFO] Mounting volume name="restart_test_volume_918109" 2017-07-11 11:45:18.176910201 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-11 11:45:18.176946268 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). Attempts left: 20 2017-07-11 11:45:18.176960282 -0700 PDT [INFO] Scheduling again after 4 seconds 2017-07-11 11:45:18.291763901 -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-07-11 11:45:22.177611283 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 11:45:22.198965992 -0700 PDT [INFO] Found 1 running or paused containers 2017-07-11 11:45:22.343976055 -0700 PDT [INFO] Discovered 1 volumes in use. 2017-07-11 11:45:22.344031665 -0700 PDT [INFO] Volume name=restart_test_volume_918109@sharedVmfs-0 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-11 11:45:22.344039573 -0700 PDT [INFO] Refcounting successfully completed 2017-07-11 11:45:39.825445913 -0700 PDT [INFO] Mounting volume name="restart_test_volume_918109" 2017-07-11 11:45:39.955576112 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_918109@sharedVmfs-0" refcount=2 2017-07-11 11:45:41.429039686 -0700 PDT [INFO] Mounting volume name="restart_test_volume_918109@sharedVmfs-0" 2017-07-11 11:45:41.429085851 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_918109@sharedVmfs-0" refcount=3 2017-07-11 11:45:42.239837562 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_918109@sharedVmfs-0" 2017-07-11 11:45:42.239890715 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_918109@sharedVmfs-0" refcount=2 2017-07-11 11:45:42.259477817 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_918109" 2017-07-11 11:45:42.259508085 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_918109@sharedVmfs-0" refcount=1 2017-07-11 11:45:42.294100643 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_918109" 2017-07-11 11:45:46.042119286 -0700 PDT [INFO] Mounting volume name="restart_test_volume_918109" 2017-07-11 11:45:47.091841343 -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-07-11 11:45:52.037478259 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-11 11:45:54.182173169 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-11 11:45:54.182238201 -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-07-11 11:45:54.182252683 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-11 11:45:54.182270213 -0700 PDT [INFO] Plugin options - port=1019 2017-07-11 11:45:54.182285315 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 11:45:54.199764224 -0700 PDT [INFO] Found 1 running or paused containers 2017-07-11 11:45:55.01998397 -0700 PDT [INFO] Discovered 1 volumes in use. 2017-07-11 11:45:55.020014731 -0700 PDT [INFO] Volume name=restart_test_volume_918109@sharedVmfs-0 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-11 11:45:55.020020334 -0700 PDT [INFO] Refcounting successfully completed 2017-07-11 11:45:55.020081785 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-11 11:45:55.020317914 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-11 11:46:05.302046308 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_918109" 2017-07-11 11:46:06.487053761 -0700 PDT [INFO] Mounting volume name="restart_test_volume_918109" 2017-07-11 11:46:07.159919924 -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-07-11 11:46:18.055116731 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_918109" 2017-07-11 11:46:24.947190766 -0700 PDT [INFO] Mounting volume name="restart_test_volume_918109" 2017-07-11 11:46:25.54359351 -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-07-11 11:46:26.589015767 -0700 PDT [INFO] Mounting volume name="restart_test_volume_918109" 2017-07-11 11:46:26.723644272 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_918109@sharedVmfs-0" refcount=2 2017-07-11 11:46:37.497654772 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_918109" 2017-07-11 11:46:37.49769011 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_918109@sharedVmfs-0" refcount=1 2017-07-11 11:46:37.572329253 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_918109" 2017-07-11 11:46:38.372226421 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-11 11:46:40.650375724 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-11 11:46:40.650435282 -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-07-11 11:46:40.650450044 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-11 11:46:40.650462076 -0700 PDT [INFO] Plugin options - port=1019 2017-07-11 11:46:40.650473111 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 11:46:42.650933672 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-11 11:46:42.651011987 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-11 11:46:42.651072971 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-11 11:46:42.651175774 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-11 11:46:42.656708229 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-11 11:46:44.656788277 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 11:46:46.051999098 -0700 PDT [INFO] Mounting volume name="restart_test_volume_918109" 2017-07-11 11:46:46.288205499 -0700 PDT [INFO] Mounting volume name="restart_test_volume_918109" 2017-07-11 11:46:46.657021542 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-11 11:46:46.657082804 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). Attempts left: 20 2017-07-11 11:46:46.657091996 -0700 PDT [INFO] Scheduling again after 4 seconds 2017-07-11 11:46:46.771647435 -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-07-11 11:46:47.039904194 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_918109@sharedVmfs-0" 2017-07-11 11:46:50.657286721 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 11:46:50.671628529 -0700 PDT [INFO] Found 2 running or paused containers 2017-07-11 11:46:50.824783634 -0700 PDT [INFO] Discovered 1 volumes in use. 2017-07-11 11:46:50.824813924 -0700 PDT [INFO] Volume name=restart_test_volume_918109@sharedVmfs-0 count=2 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-11 11:46:50.82482 -0700 PDT [INFO] Refcounting successfully completed 2017-07-11 11:47:11.762611159 -0700 PDT [INFO] Mounting volume name="restart_test_volume_918109" 2017-07-11 11:47:11.895574388 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_918109@sharedVmfs-0" refcount=3 2017-07-11 11:47:12.704648373 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_918109" 2017-07-11 11:47:12.704686055 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_918109@sharedVmfs-0" refcount=2 2017-07-11 11:47:12.77466989 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_918109" 2017-07-11 11:47:12.774726584 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_918109@sharedVmfs-0" refcount=1 2017-07-11 11:47:12.83409878 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_918109" 2017-07-11 11:47:21.509513745 -0700 PDT [INFO] Mounting volume name="restart_test_volume_918109" 2017-07-11 11:47:22.135649453 -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-07-11 11:47:36.79961837 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_918109" 2017-07-11 11:47:37.623982087 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-11 11:47:39.816481251 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-11 11:47:39.816563329 -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-07-11 11:47:39.816663924 -0700 PDT [INFO] Starting plugin log_level=info config="/etc/docker-volume-vsphere.conf" driver=vsphere 2017-07-11 11:47:39.816683317 -0700 PDT [INFO] Plugin options - port=1019 2017-07-11 11:47:39.816699035 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 11:47:41.817492441 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-11 11:47:41.817557127 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-11 11:47:41.817576627 -0700 PDT [INFO] Docker VMDK plugin started port=1019 mock_esx=false version="vSphere Volume Driver v0.5" 2017-07-11 11:47:41.818301329 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-11 11:47:41.818555858 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-11 11:47:43.818592172 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 11:47:45.134009274 -0700 PDT [INFO] Found 0 running or paused containers 2017-07-11 11:47:45.1342189 -0700 PDT [INFO] Discovered 0 volumes in use. 2017-07-11 11:47:45.134229454 -0700 PDT [INFO] Refcounting successfully completed 2017-07-11 11:48:17.56189287 -0700 PDT [INFO] Mounting volume name="restart_test_volume_918109" 2017-07-11 11:48:18.15971644 -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-07-11 11:48:19.021378357 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_918109" 2017-07-11 11:48:20.508644343 -0700 PDT [INFO] Removing volume name="restart_test_volume_918109" 2017-07-11 11:48:39.95950285 -0700 PDT [INFO] Attaching volume and creating filesystem name="basicVGTest_volume_371596" fstype=ext4 2017-07-11 11:48:40.427654087 -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-07-11 11:48:41.119489693 -0700 PDT [INFO] Volume and filesystem created name="basicVGTest_volume_371596" fstype=ext4 2017-07-11 11:48:53.028923471 -0700 PDT [INFO] Removing volume name="basicVGTest_volume_371596" 2017-07-11 11:51:10.53697404 -0700 PDT [INFO] Removing volume name="VmGroupTest.TestVmGroupVolumeAccessAcrossVmGroups_volume_190155" 2017-07-11 11:53:47.805839803 -0700 PDT [INFO] Mounting volume name="vmlistener_test_volume_727817" 2017-07-11 11:53:48.410764796 -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-07-11 11:53:53.025184533 -0700 PDT [INFO] Unmounting Volume name="vmlistener_test_volume_727817" 2017-07-11 11:54:55.007474341 -0700 PDT [INFO] Mounting volume name="vmlistener_test_volume_582576@vsanDatastore" 2017-07-11 11:54:55.599713398 -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-07-11 11:54:59.841456957 -0700 PDT [INFO] Unmounting Volume name="vmlistener_test_volume_582576@vsanDatastore" 2017-07-11 12:04:42.375625808 -0700 PDT [INFO] Attaching volume and creating filesystem name=volTestP10 fstype=ext4 2017-07-11 12:04:43.487866759 -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-07-11 12:04:44.255582284 -0700 PDT [INFO] Volume and filesystem created name=volTestP10 fstype=ext4 2017-07-11 12:04:44.377485398 -0700 PDT [INFO] Removing volume name=volTestP10 2017-07-11 12:04:45.395573935 -0700 PDT [INFO] Attaching volume and creating filesystem name=volTestP11 fstype=ext4 2017-07-11 12:04:46.119777333 -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-07-11 12:04:46.823526579 -0700 PDT [INFO] Volume and filesystem created name=volTestP11 fstype=ext4 2017-07-11 12:04:46.932969702 -0700 PDT [INFO] Removing volume name=volTestP11 2017-07-11 12:04:47.89952751 -0700 PDT [INFO] Attaching volume and creating filesystem name=volTestP12 fstype=ext4 2017-07-11 12:04:48.551600795 -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-07-11 12:04:49.687573359 -0700 PDT [INFO] Volume and filesystem created fstype=ext4 name=volTestP12 2017-07-11 12:04:49.853311566 -0700 PDT [INFO] Removing volume name=volTestP12 2017-07-11 12:05:00.809494408 -0700 PDT [INFO] Removing volume name=volTestPClone-clone10 2017-07-11 12:05:03.824725031 -0700 PDT [INFO] Removing volume name=volTestPClone-clone11 2017-07-11 15:02:42.48167091 -0700 PDT [INFO] Removing volume name="BasicTestSuite.TestVmGroupVolumeIsolation_volume_1043673" 2017-07-11 15:03:08.19956576 -0700 PDT [INFO] Attaching volume and creating filesystem name="BasicTestSuite.TestVolumeLifecycle_volume_462399" fstype=ext4 2017-07-11 15:03:08.743977361 -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-07-11 15:03:09.483605689 -0700 PDT [INFO] Volume and filesystem created name="BasicTestSuite.TestVolumeLifecycle_volume_462399" fstype=ext4 2017-07-11 15:03:11.185560321 -0700 PDT [INFO] Mounting volume name="BasicTestSuite.TestVolumeLifecycle_volume_462399" 2017-07-11 15:03:11.847566927 -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-07-11 15:03:17.080320442 -0700 PDT [INFO] Unmounting Volume name="BasicTestSuite.TestVolumeLifecycle_volume_462399" 2017-07-11 15:03:23.012509569 -0700 PDT [INFO] Removing volume name="BasicTestSuite.TestVolumeLifecycle_volume_462399" 2017-07-11 15:03:29.623240351 -0700 PDT [INFO] Mounting volume name="vol_access_volume_756613@sharedVmfs-0" 2017-07-11 15:03:30.283669476 -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-07-11 15:03:30.705025211 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_756613@sharedVmfs-0" 2017-07-11 15:03:31.804255853 -0700 PDT [INFO] Mounting volume name="vol_access_volume_756613@sharedVmfs-0" 2017-07-11 15:03:32.459610856 -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-07-11 15:03:32.862993327 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_756613@sharedVmfs-0" 2017-07-11 15:03:39.949258217 -0700 PDT [INFO] Mounting volume name="vol_access_volume_756613@sharedVmfs-0" 2017-07-11 15:03:40.567749326 -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-07-11 15:03:40.893755024 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_756613@sharedVmfs-0" 2017-07-11 15:03:45.326923014 -0700 PDT [INFO] Mounting volume name="vol_access_volume_756613@sharedVmfs-0" 2017-07-11 15:03:45.99158213 -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-07-11 15:03:46.406189371 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_756613@sharedVmfs-0" 2017-07-11 15:03:47.540191579 -0700 PDT [INFO] Mounting volume name="vol_access_volume_756613@sharedVmfs-0" 2017-07-11 15:03:48.215611538 -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-07-11 15:03:48.606440971 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_756613@sharedVmfs-0" 2017-07-11 15:03:58.091292532 -0700 PDT [INFO] Mounting volume name="vol_access_volume_833891@sharedVmfs-0" 2017-07-11 15:03:58.783699464 -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-07-11 15:03:59.121848545 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_833891@sharedVmfs-0" 2017-07-11 15:04:04.305362596 -0700 PDT [INFO] Mounting volume name="vol_access_volume_833891@sharedVmfs-0" 2017-07-11 15:04:04.979593391 -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-07-11 15:04:05.426971072 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_833891@sharedVmfs-0" 2017-07-11 15:04:06.743152926 -0700 PDT [INFO] Mounting volume name="vol_access_volume_833891@sharedVmfs-0" 2017-07-11 15:04:07.339594788 -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-07-11 15:04:07.700963577 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_833891@sharedVmfs-0" 2017-07-11 15:04:13.51152794 -0700 PDT [INFO] Attaching volume and creating filesystem name="thin_volume_731419" fstype=ext4 2017-07-11 15:04:14.015582561 -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-07-11 15:04:14.675552662 -0700 PDT [INFO] Volume and filesystem created name="thin_volume_731419" fstype=ext4 2017-07-11 15:04:15.767509924 -0700 PDT [INFO] Attaching volume and creating filesystem name="zeroedthick_volume_585153" fstype=ext4 2017-07-11 15:04:16.2676625 -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-07-11 15:04:17.011614728 -0700 PDT [INFO] Volume and filesystem created name="zeroedthick_volume_585153" fstype=ext4 2017-07-11 15:04:18.403517992 -0700 PDT [INFO] Attaching volume and creating filesystem name="eagerzeroedthick_volume_966674" fstype=ext4 2017-07-11 15:04:18.923794242 -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-07-11 15:04:19.551549712 -0700 PDT [INFO] Volume and filesystem created name="eagerzeroedthick_volume_966674" fstype=ext4 2017-07-11 15:04:33.735507458 -0700 PDT [INFO] Mounting volume name="thin_volume_731419" 2017-07-11 15:04:34.395608012 -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-07-11 15:04:37.089721211 -0700 PDT [INFO] Unmounting Volume name="thin_volume_731419" 2017-07-11 15:04:38.080773541 -0700 PDT [INFO] Removing volume name="thin_volume_731419" 2017-07-11 15:04:38.528980464 -0700 PDT [INFO] Removing volume name="zeroedthick_volume_585153" 2017-07-11 15:04:38.924580824 -0700 PDT [INFO] Removing volume name="eagerzeroedthick_volume_966674" 2017-07-11 15:07:07.323817394 -0700 PDT [INFO] Attaching volume and creating filesystem name="restart_test_volume_679615" fstype=ext4 2017-07-11 15:07:07.759824188 -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-07-11 15:07:08.407549845 -0700 PDT [INFO] Volume and filesystem created name="restart_test_volume_679615" fstype=ext4 2017-07-11 15:07:11.055532191 -0700 PDT [INFO] Attaching volume and creating filesystem name="restart_test_volume_679615@sharedVmfs-1" fstype=ext4 2017-07-11 15:07:11.563584376 -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-07-11 15:07:12.219515286 -0700 PDT [INFO] Volume and filesystem created name="restart_test_volume_679615@sharedVmfs-1" fstype=ext4 2017-07-11 15:07:12.938245896 -0700 PDT [INFO] Mounting volume name="restart_test_volume_679615" 2017-07-11 15:07:13.471636347 -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-07-11 15:07:14.588050512 -0700 PDT [INFO] Mounting volume name="restart_test_volume_679615@sharedVmfs-1" 2017-07-11 15:07:15.219639343 -0700 PDT [INFO] Scan complete event="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0": 0x100 == IN_CREATE device="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0" 2017-07-11 15:07:26.668953648 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_679615@sharedVmfs-1" 2017-07-11 15:07:26.696253984 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_679615" 2017-07-11 15:07:27.56015813 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-11 15:07:29.805211228 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-11 15:07:29.805539819 -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-07-11 15:07:29.805553641 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-11 15:07:29.805562896 -0700 PDT [INFO] Plugin options - port=1019 2017-07-11 15:07:29.805692472 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 15:07:31.806135986 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-11 15:07:31.806177485 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-11 15:07:31.806193012 -0700 PDT [INFO] Docker VMDK plugin started mock_esx=false version="vSphere Volume Driver v0.5" port=1019 2017-07-11 15:07:31.80758118 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-11 15:07:31.807944801 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-11 15:07:33.808465352 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 15:07:35.232333565 -0700 PDT [INFO] Mounting volume name="restart_test_volume_679615" 2017-07-11 15:07:35.356219018 -0700 PDT [INFO] Mounting volume name="restart_test_volume_679615@sharedVmfs-1" 2017-07-11 15:07:35.808716897 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-11 15:07:35.808827 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). Attempts left: 20 2017-07-11 15:07:35.808835692 -0700 PDT [INFO] Scheduling again after 4 seconds 2017-07-11 15:07:35.871817614 -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-07-11 15:07:36.695652002 -0700 PDT [INFO] Scan complete device="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0" event="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0": 0x100 == IN_CREATE 2017-07-11 15:07:39.80902252 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 15:07:39.861336548 -0700 PDT [INFO] Found 2 running or paused containers 2017-07-11 15:07:39.99989716 -0700 PDT [INFO] Discovered 2 volumes in use. 2017-07-11 15:07:39.999931171 -0700 PDT [INFO] Volume name=restart_test_volume_679615@sharedVmfs-1 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0' 2017-07-11 15:07:39.999937541 -0700 PDT [INFO] Volume name=restart_test_volume_679615@sharedVmfs-0 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-11 15:07:39.999942319 -0700 PDT [INFO] Refcounting successfully completed 2017-07-11 15:07:57.849130447 -0700 PDT [INFO] Mounting volume name="restart_test_volume_679615@sharedVmfs-0" 2017-07-11 15:07:57.849168068 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_679615@sharedVmfs-0" refcount=2 2017-07-11 15:07:58.73814576 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_679615@sharedVmfs-0" 2017-07-11 15:07:58.738181737 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_679615@sharedVmfs-0" refcount=1 2017-07-11 15:07:58.75798951 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_679615@sharedVmfs-1" 2017-07-11 15:07:58.808173837 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_679615" 2017-07-11 15:08:00.14066192 -0700 PDT [INFO] Removing volume name="restart_test_volume_679615@sharedVmfs-1" 2017-07-11 15:08:04.201730533 -0700 PDT [INFO] Mounting volume name="restart_test_volume_679615" 2017-07-11 15:08:04.883635309 -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-07-11 15:08:15.782752359 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_679615" 2017-07-11 15:08:16.271959045 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-11 15:08:18.472505755 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-11 15:08:18.473300038 -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-07-11 15:08:18.473359915 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-11 15:08:18.473374759 -0700 PDT [INFO] Plugin options - port=1019 2017-07-11 15:08:18.473406261 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 15:08:20.473757541 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-11 15:08:20.473798283 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-11 15:08:20.473813565 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-11 15:08:20.474031177 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-11 15:08:20.476971502 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-11 15:08:22.474710576 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 15:08:23.576297978 -0700 PDT [INFO] Mounting volume name="restart_test_volume_679615" 2017-07-11 15:08:24.111730216 -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-07-11 15:08:24.397204496 -0700 PDT [INFO] Found 1 running or paused containers 2017-07-11 15:08:24.499898327 -0700 PDT [INFO] Discovered 1 volumes in use. 2017-07-11 15:08:24.499932673 -0700 PDT [INFO] Volume name=restart_test_volume_679615@sharedVmfs-0 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-11 15:08:24.499938418 -0700 PDT [INFO] Refcounting successfully completed 2017-07-11 15:08:45.391899904 -0700 PDT [INFO] Mounting volume name="restart_test_volume_679615" 2017-07-11 15:08:45.487701084 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_679615@sharedVmfs-0" refcount=2 2017-07-11 15:08:46.893489726 -0700 PDT [INFO] Mounting volume name="restart_test_volume_679615@sharedVmfs-0" 2017-07-11 15:08:46.893532858 -0700 PDT [INFO] Already mounted, skipping mount. refcount=3 name="restart_test_volume_679615@sharedVmfs-0" 2017-07-11 15:08:47.74492047 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_679615" 2017-07-11 15:08:47.744964151 -0700 PDT [INFO] Still in use, skipping unmount request. refcount=2 name="restart_test_volume_679615@sharedVmfs-0" 2017-07-11 15:08:47.766739551 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_679615" 2017-07-11 15:08:47.766773167 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_679615@sharedVmfs-0" refcount=1 2017-07-11 15:08:47.818133356 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_679615@sharedVmfs-0" 2017-07-11 15:08:51.695118612 -0700 PDT [INFO] Mounting volume name="restart_test_volume_679615" 2017-07-11 15:08:52.359727879 -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-07-11 15:08:57.290169603 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-11 15:08:59.532672617 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-11 15:08:59.532883042 -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-07-11 15:08:59.532895864 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-11 15:08:59.532909267 -0700 PDT [INFO] Plugin options - port=1019 2017-07-11 15:08:59.532932871 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 15:08:59.567669067 -0700 PDT [INFO] Found 1 running or paused containers 2017-07-11 15:08:59.907931468 -0700 PDT [INFO] Discovered 1 volumes in use. 2017-07-11 15:08:59.907992771 -0700 PDT [INFO] Volume name=restart_test_volume_679615@sharedVmfs-0 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-11 15:08:59.907999665 -0700 PDT [INFO] Refcounting successfully completed 2017-07-11 15:08:59.908007543 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-11 15:08:59.908564827 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-11 15:09:10.487036798 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_679615" 2017-07-11 15:09:11.689381174 -0700 PDT [INFO] Mounting volume name="restart_test_volume_679615" 2017-07-11 15:09:12.26926572 -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-07-11 15:09:23.198394015 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_679615" 2017-07-11 15:09:29.265522814 -0700 PDT [INFO] Mounting volume name="restart_test_volume_679615" 2017-07-11 15:09:29.783598063 -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-07-11 15:09:30.905229137 -0700 PDT [INFO] Mounting volume name="restart_test_volume_679615" 2017-07-11 15:09:31.003644756 -0700 PDT [INFO] Already mounted, skipping mount. refcount=2 name="restart_test_volume_679615@sharedVmfs-0" 2017-07-11 15:09:41.849922416 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_679615" 2017-07-11 15:09:41.849968951 -0700 PDT [INFO] Still in use, skipping unmount request. refcount=1 name="restart_test_volume_679615@sharedVmfs-0" 2017-07-11 15:09:41.856132211 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_679615" 2017-07-11 15:09:42.336116517 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-11 15:09:44.554204274 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-11 15:09:44.554298755 -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-07-11 15:09:44.554309022 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-11 15:09:44.554317805 -0700 PDT [INFO] Plugin options - port=1019 2017-07-11 15:09:44.554328412 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 15:09:46.554927649 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-11 15:09:46.555012755 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-11 15:09:46.555065983 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-11 15:09:46.555206073 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-11 15:09:46.555932287 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-11 15:09:48.55605639 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 15:09:49.944339307 -0700 PDT [INFO] Mounting volume name="restart_test_volume_679615" 2017-07-11 15:09:50.112300738 -0700 PDT [INFO] Mounting volume name="restart_test_volume_679615" 2017-07-11 15:09:50.551686526 -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-07-11 15:09:50.617148172 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-11 15:09:50.617211962 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). Attempts left: 20 2017-07-11 15:09:50.617220366 -0700 PDT [INFO] Scheduling again after 4 seconds 2017-07-11 15:09:50.803419677 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_679615@sharedVmfs-0" 2017-07-11 15:09:54.617446298 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 15:09:54.64000569 -0700 PDT [INFO] Found 2 running or paused containers 2017-07-11 15:09:54.765120634 -0700 PDT [INFO] Discovered 1 volumes in use. 2017-07-11 15:09:54.765148984 -0700 PDT [INFO] Volume name=restart_test_volume_679615@sharedVmfs-0 count=2 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-11 15:09:54.765157419 -0700 PDT [INFO] Refcounting successfully completed 2017-07-11 15:10:15.365610453 -0700 PDT [INFO] Mounting volume name="restart_test_volume_679615" 2017-07-11 15:10:15.468518553 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_679615@sharedVmfs-0" refcount=3 2017-07-11 15:10:16.305828997 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_679615" 2017-07-11 15:10:16.305868652 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_679615@sharedVmfs-0" refcount=2 2017-07-11 15:10:16.363780521 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_679615" 2017-07-11 15:10:16.363815863 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_679615@sharedVmfs-0" refcount=1 2017-07-11 15:10:16.388671818 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_679615" 2017-07-11 15:10:24.849792332 -0700 PDT [INFO] Mounting volume name="restart_test_volume_679615" 2017-07-11 15:10:25.447591041 -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-07-11 15:10:39.995468445 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_679615" 2017-07-11 15:10:40.492164228 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-11 15:10:42.694738306 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-11 15:10:42.694873054 -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-07-11 15:10:42.694882453 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-11 15:10:42.694891342 -0700 PDT [INFO] Plugin options - port=1019 2017-07-11 15:10:42.694906929 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 15:10:44.695710867 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-11 15:10:44.695868399 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-11 15:10:44.695901814 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-11 15:10:44.696040218 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-11 15:10:44.696227334 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-11 15:10:46.696335362 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-11 15:10:48.055343561 -0700 PDT [INFO] Found 0 running or paused containers 2017-07-11 15:10:48.055621099 -0700 PDT [INFO] Discovered 0 volumes in use. 2017-07-11 15:10:48.055640066 -0700 PDT [INFO] Refcounting successfully completed 2017-07-11 15:11:21.260595625 -0700 PDT [INFO] Mounting volume name="restart_test_volume_679615" 2017-07-11 15:11:21.81168938 -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-07-11 15:11:22.61696603 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_679615" 2017-07-11 15:11:24.088851137 -0700 PDT [INFO] Removing volume name="restart_test_volume_679615" 2017-07-11 15:11:40.311530004 -0700 PDT [INFO] Attaching volume and creating filesystem name="basicVGTest_volume_682546" fstype=ext4 2017-07-11 15:11:40.767760694 -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-07-11 15:11:41.459548198 -0700 PDT [INFO] Volume and filesystem created name="basicVGTest_volume_682546" fstype=ext4 2017-07-11 15:11:53.681187662 -0700 PDT [INFO] Removing volume name="basicVGTest_volume_682546" 2017-07-11 15:14:09.293716267 -0700 PDT [INFO] Removing volume name="VmGroupTest.TestVmGroupVolumeAccessAcrossVmGroups_volume_159683" 2017-07-11 15:16:52.340634156 -0700 PDT [INFO] Mounting volume name="vmlistener_test_volume_874943" 2017-07-11 15:16:52.863890744 -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-07-11 15:16:57.337692655 -0700 PDT [INFO] Unmounting Volume name="vmlistener_test_volume_874943" 2017-07-11 15:18:02.104175128 -0700 PDT [INFO] Mounting volume name="vmlistener_test_volume_710057@vsanDatastore" 2017-07-11 15:18:02.755586451 -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-07-11 15:18:07.414891978 -0700 PDT [INFO] Unmounting Volume name="vmlistener_test_volume_710057@vsanDatastore" 2017-07-12 09:54:23.305457573 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-12 09:57:07.22451569 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-12 09:57:07.224819458 -0700 PDT [INFO] Starting plugin config="/etc/docker-volume-vsphere.conf" driver=vsphere log_level=info 2017-07-12 09:57:07.224849924 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 09:57:07.243464612 -0700 PDT [INFO] Found 0 running or paused containers 2017-07-12 09:57:07.243763165 -0700 PDT [INFO] Discovered 0 volumes in use. 2017-07-12 09:57:07.24377561 -0700 PDT [INFO] Refcounting successfully completed 2017-07-12 09:57:07.243815088 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-12 09:57:07.243963414 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-12 09:58:25.266518051 -0700 PDT [INFO] Removing volume name="BasicTestSuite.TestVmGroupVolumeIsolation_volume_265640" 2017-07-12 09:58:47.775494541 -0700 PDT [INFO] Attaching volume and creating filesystem name="BasicTestSuite.TestVolumeLifecycle_volume_1041168" fstype=ext4 2017-07-12 09:58:48.355915718 -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-07-12 09:58:49.035518922 -0700 PDT [INFO] Volume and filesystem created fstype=ext4 name="BasicTestSuite.TestVolumeLifecycle_volume_1041168" 2017-07-12 09:58:50.640340925 -0700 PDT [INFO] Mounting volume name="BasicTestSuite.TestVolumeLifecycle_volume_1041168" 2017-07-12 09:58:51.307655353 -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-07-12 09:58:56.357480875 -0700 PDT [INFO] Unmounting Volume name="BasicTestSuite.TestVolumeLifecycle_volume_1041168" 2017-07-12 09:59:00.484911587 -0700 PDT [INFO] Removing volume name="BasicTestSuite.TestVolumeLifecycle_volume_1041168" 2017-07-12 09:59:08.87595936 -0700 PDT [INFO] Mounting volume name="vol_access_volume_793291@sharedVmfs-0" 2017-07-12 09:59:09.555714368 -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-07-12 09:59:10.049662023 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_793291@sharedVmfs-0" 2017-07-12 09:59:11.500050579 -0700 PDT [INFO] Mounting volume name="vol_access_volume_793291@sharedVmfs-0" 2017-07-12 09:59:12.147570496 -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-07-12 09:59:12.561095913 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_793291@sharedVmfs-0" 2017-07-12 09:59:19.683592841 -0700 PDT [INFO] Mounting volume name="vol_access_volume_793291@sharedVmfs-0" 2017-07-12 09:59:20.419687882 -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-07-12 09:59:20.749069115 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_793291@sharedVmfs-0" 2017-07-12 09:59:25.12922727 -0700 PDT [INFO] Mounting volume name="vol_access_volume_793291@sharedVmfs-0" 2017-07-12 09:59:25.757159138 -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-07-12 09:59:26.162366511 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_793291@sharedVmfs-0" 2017-07-12 09:59:27.674363235 -0700 PDT [INFO] Mounting volume name="vol_access_volume_793291@sharedVmfs-0" 2017-07-12 09:59:28.271617745 -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-07-12 09:59:28.671883035 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_793291@sharedVmfs-0" 2017-07-12 09:59:37.546642109 -0700 PDT [INFO] Mounting volume name="vol_access_volume_842054@sharedVmfs-0" 2017-07-12 09:59:38.183811159 -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-07-12 09:59:38.473305412 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_842054@sharedVmfs-0" 2017-07-12 09:59:43.008132976 -0700 PDT [INFO] Mounting volume name="vol_access_volume_842054@sharedVmfs-0" 2017-07-12 09:59:43.691599905 -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-07-12 09:59:44.09975043 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_842054@sharedVmfs-0" 2017-07-12 09:59:45.194750284 -0700 PDT [INFO] Mounting volume name="vol_access_volume_842054@sharedVmfs-0" 2017-07-12 09:59:45.823587393 -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-07-12 09:59:46.229068095 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_842054@sharedVmfs-0" 2017-07-12 09:59:51.559536218 -0700 PDT [INFO] Attaching volume and creating filesystem name="thin_volume_660939" fstype=ext4 2017-07-12 09:59:52.039584724 -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-07-12 09:59:52.715541838 -0700 PDT [INFO] Volume and filesystem created fstype=ext4 name="thin_volume_660939" 2017-07-12 09:59:54.067515371 -0700 PDT [INFO] Attaching volume and creating filesystem name="zeroedthick_volume_309555" fstype=ext4 2017-07-12 09:59:54.559607141 -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-07-12 09:59:55.191505993 -0700 PDT [INFO] Volume and filesystem created name="zeroedthick_volume_309555" fstype=ext4 2017-07-12 09:59:56.591485876 -0700 PDT [INFO] Attaching volume and creating filesystem name="eagerzeroedthick_volume_908488" fstype=ext4 2017-07-12 09:59:57.14360741 -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-07-12 09:59:57.727483133 -0700 PDT [INFO] Volume and filesystem created name="eagerzeroedthick_volume_908488" fstype=ext4 2017-07-12 10:00:05.216177267 -0700 PDT [INFO] Mounting volume name="thin_volume_660939" 2017-07-12 10:00:05.87956833 -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-07-12 10:00:09.131458611 -0700 PDT [INFO] Unmounting Volume name="thin_volume_660939" 2017-07-12 10:00:10.448588915 -0700 PDT [INFO] Removing volume name="thin_volume_660939" 2017-07-12 10:00:10.872349254 -0700 PDT [INFO] Removing volume name="zeroedthick_volume_309555" 2017-07-12 10:00:11.316547912 -0700 PDT [INFO] Removing volume name="eagerzeroedthick_volume_908488" 2017-07-12 10:02:40.771539717 -0700 PDT [INFO] Attaching volume and creating filesystem name="restart_test_volume_750611" fstype=ext4 2017-07-12 10:02:41.223609406 -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-07-12 10:02:41.859578524 -0700 PDT [INFO] Volume and filesystem created fstype=ext4 name="restart_test_volume_750611" 2017-07-12 10:02:44.523499088 -0700 PDT [INFO] Attaching volume and creating filesystem name="restart_test_volume_750611@sharedVmfs-1" fstype=ext4 2017-07-12 10:02:45.051604167 -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-07-12 10:02:45.675538868 -0700 PDT [INFO] Volume and filesystem created fstype=ext4 name="restart_test_volume_750611@sharedVmfs-1" 2017-07-12 10:02:46.374276394 -0700 PDT [INFO] Mounting volume name="restart_test_volume_750611" 2017-07-12 10:02:46.915652466 -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-07-12 10:02:47.976868115 -0700 PDT [INFO] Mounting volume name="restart_test_volume_750611@sharedVmfs-1" 2017-07-12 10:02:48.591618065 -0700 PDT [INFO] Scan complete device="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0" event="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0": 0x100 == IN_CREATE 2017-07-12 10:03:00.081832667 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_750611@sharedVmfs-1" 2017-07-12 10:03:00.141561179 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_750611" 2017-07-12 10:03:01.128203786 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-12 10:03:03.342743445 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-12 10:03:03.342839582 -0700 PDT [INFO] Starting plugin config="/etc/docker-volume-vsphere.conf" driver=vsphere log_level=info 2017-07-12 10:03:03.342936586 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 10:03:05.343239188 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-12 10:03:05.343281273 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-12 10:03:05.343302893 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-12 10:03:05.343937767 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-12 10:03:05.343983995 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-12 10:03:07.344164731 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 10:03:09.344500343 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-12 10:03:09.34454997 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). Attempts left: 20 2017-07-12 10:03:09.344560128 -0700 PDT [INFO] Scheduling again after 4 seconds 2017-07-12 10:03:09.360285147 -0700 PDT [INFO] Mounting volume name="restart_test_volume_750611@sharedVmfs-1" 2017-07-12 10:03:09.456631151 -0700 PDT [INFO] Mounting volume name="restart_test_volume_750611" 2017-07-12 10:03:10.131678704 -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-07-12 10:03:10.887625468 -0700 PDT [INFO] Scan complete event="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0": 0x100 == IN_CREATE device="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0" 2017-07-12 10:03:13.344945319 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 10:03:13.360272454 -0700 PDT [INFO] Found 2 running or paused containers 2017-07-12 10:03:13.620102637 -0700 PDT [INFO] Discovered 2 volumes in use. 2017-07-12 10:03:13.620136064 -0700 PDT [INFO] Volume name=restart_test_volume_750611@sharedVmfs-1 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-12 10:03:13.620142786 -0700 PDT [INFO] Volume name=restart_test_volume_750611@sharedVmfs-0 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0' 2017-07-12 10:03:13.620150205 -0700 PDT [INFO] Refcounting successfully completed 2017-07-12 10:03:32.163978309 -0700 PDT [INFO] Mounting volume name="restart_test_volume_750611@sharedVmfs-0" 2017-07-12 10:03:32.164014816 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_750611@sharedVmfs-0" refcount=2 2017-07-12 10:03:33.06600198 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_750611@sharedVmfs-0" 2017-07-12 10:03:33.066042748 -0700 PDT [INFO] Still in use, skipping unmount request. refcount=1 name="restart_test_volume_750611@sharedVmfs-0" 2017-07-12 10:03:33.129838204 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_750611" 2017-07-12 10:03:33.153017517 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_750611@sharedVmfs-1" 2017-07-12 10:03:34.464566157 -0700 PDT [INFO] Removing volume name="restart_test_volume_750611@sharedVmfs-1" 2017-07-12 10:03:37.990157954 -0700 PDT [INFO] Mounting volume name="restart_test_volume_750611" 2017-07-12 10:03:38.670035789 -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-07-12 10:03:49.650969125 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_750611" 2017-07-12 10:03:50.143986568 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-12 10:03:52.342070377 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-12 10:03:52.342099848 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-12 10:03:52.342119426 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 10:03:54.342958068 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-12 10:03:54.34303561 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-12 10:03:54.343058137 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-12 10:03:54.34319999 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-12 10:03:54.343487584 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-12 10:03:56.34351774 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 10:03:58.024591665 -0700 PDT [INFO] Mounting volume name="restart_test_volume_750611" 2017-07-12 10:03:58.343770613 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-12 10:03:58.343856704 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). Attempts left: 20 2017-07-12 10:03:58.343877379 -0700 PDT [INFO] Scheduling again after 4 seconds 2017-07-12 10:03:58.579712385 -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-07-12 10:04:02.344164416 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 10:04:02.357765431 -0700 PDT [INFO] Found 1 running or paused containers 2017-07-12 10:04:02.499860717 -0700 PDT [INFO] Discovered 1 volumes in use. 2017-07-12 10:04:02.4998936 -0700 PDT [INFO] Volume name=restart_test_volume_750611@sharedVmfs-0 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-12 10:04:02.499899216 -0700 PDT [INFO] Refcounting successfully completed 2017-07-12 10:04:19.786690576 -0700 PDT [INFO] Mounting volume name="restart_test_volume_750611" 2017-07-12 10:04:19.879639569 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_750611@sharedVmfs-0" refcount=2 2017-07-12 10:04:21.406588846 -0700 PDT [INFO] Mounting volume name="restart_test_volume_750611@sharedVmfs-0" 2017-07-12 10:04:21.406624713 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_750611@sharedVmfs-0" refcount=3 2017-07-12 10:04:22.30568781 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_750611" 2017-07-12 10:04:22.305745209 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_750611@sharedVmfs-0" refcount=2 2017-07-12 10:04:22.318751226 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_750611@sharedVmfs-0" 2017-07-12 10:04:22.318780979 -0700 PDT [INFO] Still in use, skipping unmount request. refcount=1 name="restart_test_volume_750611@sharedVmfs-0" 2017-07-12 10:04:22.340448394 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_750611" 2017-07-12 10:04:25.77470966 -0700 PDT [INFO] Mounting volume name="restart_test_volume_750611" 2017-07-12 10:04:26.435820333 -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-07-12 10:04:31.330868681 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-12 10:04:33.49987192 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-12 10:04:33.499906293 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-12 10:04:33.499979282 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 10:04:33.522371184 -0700 PDT [INFO] Found 1 running or paused containers 2017-07-12 10:04:33.860006501 -0700 PDT [INFO] Discovered 1 volumes in use. 2017-07-12 10:04:33.860048305 -0700 PDT [INFO] Volume name=restart_test_volume_750611@sharedVmfs-0 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-12 10:04:33.860055217 -0700 PDT [INFO] Refcounting successfully completed 2017-07-12 10:04:33.860121726 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-12 10:04:33.860676099 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-12 10:04:44.528819106 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_750611" 2017-07-12 10:04:45.644171161 -0700 PDT [INFO] Mounting volume name="restart_test_volume_750611" 2017-07-12 10:04:46.171849845 -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-07-12 10:04:57.053256285 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_750611" 2017-07-12 10:05:01.691130982 -0700 PDT [INFO] Mounting volume name="restart_test_volume_750611" 2017-07-12 10:05:02.267683188 -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-07-12 10:05:03.451259902 -0700 PDT [INFO] Mounting volume name="restart_test_volume_750611" 2017-07-12 10:05:03.555792512 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_750611@sharedVmfs-0" refcount=2 2017-07-12 10:05:14.452262794 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_750611" 2017-07-12 10:05:14.452302843 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_750611@sharedVmfs-0" refcount=1 2017-07-12 10:05:14.469720436 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_750611" 2017-07-12 10:05:14.964042655 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-12 10:05:17.188399568 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-12 10:05:17.188491441 -0700 PDT [INFO] Starting plugin log_level=info config="/etc/docker-volume-vsphere.conf" driver=vsphere 2017-07-12 10:05:17.188520944 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 10:05:19.18909787 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-12 10:05:19.189177035 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-12 10:05:19.189200618 -0700 PDT [INFO] Docker VMDK plugin started mock_esx=false version="vSphere Volume Driver v0.5" port=1019 2017-07-12 10:05:19.189375159 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-12 10:05:19.189562053 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-12 10:05:21.18974059 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 10:05:23.189965641 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-12 10:05:23.190018435 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). Attempts left: 20 2017-07-12 10:05:23.190026992 -0700 PDT [INFO] Scheduling again after 4 seconds 2017-07-12 10:05:23.192170483 -0700 PDT [INFO] Mounting volume name="restart_test_volume_750611" 2017-07-12 10:05:23.376768765 -0700 PDT [INFO] Mounting volume name="restart_test_volume_750611" 2017-07-12 10:05:23.815675978 -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-07-12 10:05:24.107861484 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_750611@sharedVmfs-0" 2017-07-12 10:05:27.190255845 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 10:05:27.208477227 -0700 PDT [INFO] Found 2 running or paused containers 2017-07-12 10:05:27.345238474 -0700 PDT [INFO] Discovered 1 volumes in use. 2017-07-12 10:05:27.345268302 -0700 PDT [INFO] Volume name=restart_test_volume_750611@sharedVmfs-0 count=2 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-12 10:05:27.345280809 -0700 PDT [INFO] Refcounting successfully completed 2017-07-12 10:05:48.516173562 -0700 PDT [INFO] Mounting volume name="restart_test_volume_750611" 2017-07-12 10:05:48.615767493 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_750611@sharedVmfs-0" refcount=3 2017-07-12 10:05:49.476832888 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_750611" 2017-07-12 10:05:49.476874749 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_750611@sharedVmfs-0" refcount=2 2017-07-12 10:05:49.509144655 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_750611" 2017-07-12 10:05:49.509178685 -0700 PDT [INFO] Still in use, skipping unmount request. refcount=1 name="restart_test_volume_750611@sharedVmfs-0" 2017-07-12 10:05:49.524913885 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_750611" 2017-07-12 10:05:56.017885806 -0700 PDT [INFO] Mounting volume name="restart_test_volume_750611" 2017-07-12 10:05:56.631793312 -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-07-12 10:06:11.09406615 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_750611" 2017-07-12 10:06:11.616027692 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-12 10:06:13.843927925 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-12 10:06:13.843964152 -0700 PDT [INFO] Starting plugin log_level=info config="/etc/docker-volume-vsphere.conf" driver=vsphere 2017-07-12 10:06:13.844079604 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 10:06:15.844988719 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-12 10:06:15.845071795 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-12 10:06:15.845096766 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-12 10:06:15.845187723 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-12 10:06:15.845537657 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-12 10:06:17.845942377 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 10:06:19.809703849 -0700 PDT [INFO] Found 0 running or paused containers 2017-07-12 10:06:19.810025853 -0700 PDT [INFO] Discovered 0 volumes in use. 2017-07-12 10:06:19.810039414 -0700 PDT [INFO] Refcounting successfully completed 2017-07-12 10:06:49.121061219 -0700 PDT [INFO] Mounting volume name="restart_test_volume_750611" 2017-07-12 10:06:49.851733556 -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-07-12 10:06:50.721697666 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_750611" 2017-07-12 10:06:52.168556824 -0700 PDT [INFO] Removing volume name="restart_test_volume_750611" 2017-07-12 10:07:10.987568744 -0700 PDT [INFO] Attaching volume and creating filesystem name="basicVGTest_volume_1097410" fstype=ext4 2017-07-12 10:07:11.499732016 -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-07-12 10:07:12.147520182 -0700 PDT [INFO] Volume and filesystem created fstype=ext4 name="basicVGTest_volume_1097410" 2017-07-12 10:07:24.516648641 -0700 PDT [INFO] Removing volume name="basicVGTest_volume_1097410" 2017-07-12 10:09:37.18912736 -0700 PDT [INFO] Removing volume name="VmGroupTest.TestVmGroupVolumeAccessAcrossVmGroups_volume_551734" 2017-07-12 10:12:03.951204361 -0700 PDT [INFO] Mounting volume name="vmlistener_test_volume_1013302" 2017-07-12 10:12:04.588883284 -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-07-12 10:12:09.39106377 -0700 PDT [INFO] Unmounting Volume name="vmlistener_test_volume_1013302" 2017-07-12 10:13:07.91057921 -0700 PDT [INFO] Mounting volume name="vmlistener_test_volume_1044292@vsanDatastore" 2017-07-12 10:13:08.567792897 -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-07-12 10:13:13.073628254 -0700 PDT [INFO] Unmounting Volume name="vmlistener_test_volume_1044292@vsanDatastore" 2017-07-12 11:20:37.587487905 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-12 11:29:56.576820874 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-12 11:29:56.576895778 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-12 11:29:56.576924924 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 11:29:56.605370272 -0700 PDT [INFO] Found 0 running or paused containers 2017-07-12 11:29:56.605582999 -0700 PDT [INFO] Discovered 0 volumes in use. 2017-07-12 11:29:56.605594426 -0700 PDT [INFO] Refcounting successfully completed 2017-07-12 11:29:56.605610854 -0700 PDT [INFO] Docker VMDK plugin started mock_esx=false version="vSphere Volume Driver v0.5" port=1019 2017-07-12 11:29:56.60575442 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-12 11:33:06.823668456 -0700 PDT [INFO] Removing volume name="BasicTestSuite.TestVmGroupVolumeIsolation_volume_318480" 2017-07-12 11:33:28.867594527 -0700 PDT [INFO] Attaching volume and creating filesystem name="BasicTestSuite.TestVolumeLifecycle_volume_861808" fstype=ext4 2017-07-12 11:33:29.407885543 -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-07-12 11:33:30.051490925 -0700 PDT [INFO] Volume and filesystem created fstype=ext4 name="BasicTestSuite.TestVolumeLifecycle_volume_861808" 2017-07-12 11:33:31.69086149 -0700 PDT [INFO] Mounting volume name="BasicTestSuite.TestVolumeLifecycle_volume_861808" 2017-07-12 11:33:32.323646403 -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-07-12 11:33:37.14800618 -0700 PDT [INFO] Unmounting Volume name="BasicTestSuite.TestVolumeLifecycle_volume_861808" 2017-07-12 11:33:40.872891217 -0700 PDT [INFO] Removing volume name="BasicTestSuite.TestVolumeLifecycle_volume_861808" 2017-07-12 11:33:47.139346384 -0700 PDT [INFO] Mounting volume name="vol_access_volume_336206@sharedVmfs-0" 2017-07-12 11:33:47.811578489 -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-07-12 11:33:48.225621322 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_336206@sharedVmfs-0" 2017-07-12 11:33:49.328584005 -0700 PDT [INFO] Mounting volume name="vol_access_volume_336206@sharedVmfs-0" 2017-07-12 11:33:49.955605573 -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-07-12 11:33:50.368024226 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_336206@sharedVmfs-0" 2017-07-12 11:33:56.901430713 -0700 PDT [INFO] Mounting volume name="vol_access_volume_336206@sharedVmfs-0" 2017-07-12 11:33:57.579613592 -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-07-12 11:33:57.92581139 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_336206@sharedVmfs-0" 2017-07-12 11:34:02.559343975 -0700 PDT [INFO] Mounting volume name="vol_access_volume_336206@sharedVmfs-0" 2017-07-12 11:34:03.239630762 -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-07-12 11:34:03.633199472 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_336206@sharedVmfs-0" 2017-07-12 11:34:04.833646284 -0700 PDT [INFO] Mounting volume name="vol_access_volume_336206@sharedVmfs-0" 2017-07-12 11:34:05.599572623 -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-07-12 11:34:05.990343428 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_336206@sharedVmfs-0" 2017-07-12 11:34:14.891323789 -0700 PDT [INFO] Mounting volume name="vol_access_volume_557792@sharedVmfs-0" 2017-07-12 11:34:15.543601295 -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-07-12 11:34:15.858107945 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_557792@sharedVmfs-0" 2017-07-12 11:34:20.520089977 -0700 PDT [INFO] Mounting volume name="vol_access_volume_557792@sharedVmfs-0" 2017-07-12 11:34:21.127791182 -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-07-12 11:34:21.496551253 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_557792@sharedVmfs-0" 2017-07-12 11:34:22.671424526 -0700 PDT [INFO] Mounting volume name="vol_access_volume_557792@sharedVmfs-0" 2017-07-12 11:34:23.303602858 -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-07-12 11:34:23.683083413 -0700 PDT [INFO] Unmounting Volume name="vol_access_volume_557792@sharedVmfs-0" 2017-07-12 11:34:28.563514235 -0700 PDT [INFO] Attaching volume and creating filesystem fstype=ext4 name="thin_volume_999505" 2017-07-12 11:34:29.055652326 -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-07-12 11:34:29.683559114 -0700 PDT [INFO] Volume and filesystem created name="thin_volume_999505" fstype=ext4 2017-07-12 11:34:30.859525671 -0700 PDT [INFO] Attaching volume and creating filesystem name="zeroedthick_volume_673964" fstype=ext4 2017-07-12 11:34:31.351640996 -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-07-12 11:34:32.075538887 -0700 PDT [INFO] Volume and filesystem created fstype=ext4 name="zeroedthick_volume_673964" 2017-07-12 11:34:33.543490115 -0700 PDT [INFO] Attaching volume and creating filesystem fstype=ext4 name="eagerzeroedthick_volume_693514" 2017-07-12 11:34:34.075669902 -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-07-12 11:34:34.635541703 -0700 PDT [INFO] Volume and filesystem created fstype=ext4 name="eagerzeroedthick_volume_693514" 2017-07-12 11:34:41.445132888 -0700 PDT [INFO] Mounting volume name="thin_volume_999505" 2017-07-12 11:34:42.207598619 -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-07-12 11:34:45.16519364 -0700 PDT [INFO] Unmounting Volume name="thin_volume_999505" 2017-07-12 11:34:46.308843416 -0700 PDT [INFO] Removing volume name="thin_volume_999505" 2017-07-12 11:34:46.784657772 -0700 PDT [INFO] Removing volume name="zeroedthick_volume_673964" 2017-07-12 11:34:47.18888167 -0700 PDT [INFO] Removing volume name="eagerzeroedthick_volume_693514" 2017-07-12 11:37:33.83559276 -0700 PDT [INFO] Attaching volume and creating filesystem name="restart_test_volume_353481" fstype=ext4 2017-07-12 11:37:34.315926232 -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-07-12 11:37:34.931523496 -0700 PDT [INFO] Volume and filesystem created fstype=ext4 name="restart_test_volume_353481" 2017-07-12 11:37:37.735550244 -0700 PDT [INFO] Attaching volume and creating filesystem name="restart_test_volume_353481@sharedVmfs-1" fstype=ext4 2017-07-12 11:37:38.283586513 -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-07-12 11:37:39.011510717 -0700 PDT [INFO] Volume and filesystem created name="restart_test_volume_353481@sharedVmfs-1" fstype=ext4 2017-07-12 11:37:40.050682594 -0700 PDT [INFO] Mounting volume name="restart_test_volume_353481" 2017-07-12 11:37:40.587597121 -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-07-12 11:37:41.814145179 -0700 PDT [INFO] Mounting volume name="restart_test_volume_353481@sharedVmfs-1" 2017-07-12 11:37:42.543594558 -0700 PDT [INFO] Scan complete device="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0" event="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0": 0x100 == IN_CREATE 2017-07-12 11:37:54.369520693 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_353481@sharedVmfs-1" 2017-07-12 11:37:54.392727427 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_353481" 2017-07-12 11:37:55.264249858 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-12 11:37:57.501656423 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-12 11:37:57.501737307 -0700 PDT [INFO] Starting plugin config="/etc/docker-volume-vsphere.conf" driver=vsphere log_level=info 2017-07-12 11:37:57.501853688 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 11:37:59.50319957 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-12 11:37:59.503303614 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-12 11:37:59.503376559 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-12 11:37:59.503696488 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-12 11:37:59.504208726 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-12 11:38:01.504553522 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 11:38:03.50494564 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-12 11:38:03.504986266 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). Attempts left: 20 2017-07-12 11:38:03.504993883 -0700 PDT [INFO] Scheduling again after 4 seconds 2017-07-12 11:38:04.58413205 -0700 PDT [INFO] Mounting volume name="restart_test_volume_353481@sharedVmfs-1" 2017-07-12 11:38:04.684486456 -0700 PDT [INFO] Mounting volume name="restart_test_volume_353481" 2017-07-12 11:38:05.367682745 -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-07-12 11:38:06.163610063 -0700 PDT [INFO] Scan complete device="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0" event="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0": 0x100 == IN_CREATE 2017-07-12 11:38:07.505247666 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 11:38:07.518396285 -0700 PDT [INFO] Found 2 running or paused containers 2017-07-12 11:38:07.675866637 -0700 PDT [INFO] Discovered 2 volumes in use. 2017-07-12 11:38:07.67590592 -0700 PDT [INFO] Volume name=restart_test_volume_353481@sharedVmfs-1 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-12 11:38:07.67591751 -0700 PDT [INFO] Volume name=restart_test_volume_353481@sharedVmfs-0 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0' 2017-07-12 11:38:07.675931165 -0700 PDT [INFO] Refcounting successfully completed 2017-07-12 11:38:27.353412118 -0700 PDT [INFO] Mounting volume name="restart_test_volume_353481@sharedVmfs-0" 2017-07-12 11:38:27.353450325 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_353481@sharedVmfs-0" refcount=2 2017-07-12 11:38:28.293789588 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_353481@sharedVmfs-0" 2017-07-12 11:38:28.293827403 -0700 PDT [INFO] Still in use, skipping unmount request. refcount=1 name="restart_test_volume_353481@sharedVmfs-0" 2017-07-12 11:38:28.304634883 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_353481" 2017-07-12 11:38:28.331889309 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_353481@sharedVmfs-1" 2017-07-12 11:38:29.684803324 -0700 PDT [INFO] Removing volume name="restart_test_volume_353481@sharedVmfs-1" 2017-07-12 11:38:33.164748946 -0700 PDT [INFO] Mounting volume name="restart_test_volume_353481" 2017-07-12 11:38:33.843613665 -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-07-12 11:38:44.660145782 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_353481" 2017-07-12 11:38:45.155932593 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-12 11:38:47.364409654 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-12 11:38:47.364493604 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-12 11:38:47.364571354 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 11:38:49.364817254 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-12 11:38:49.364857911 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-12 11:38:49.364873152 -0700 PDT [INFO] Docker VMDK plugin started mock_esx=false version="vSphere Volume Driver v0.5" port=1019 2017-07-12 11:38:49.365114997 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-12 11:38:49.365220145 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-12 11:38:51.365780284 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 11:38:53.366017106 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-12 11:38:53.366053313 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). Attempts left: 20 2017-07-12 11:38:53.36606033 -0700 PDT [INFO] Scheduling again after 4 seconds 2017-07-12 11:38:53.664137938 -0700 PDT [INFO] Mounting volume name="restart_test_volume_353481" 2017-07-12 11:38:54.199707528 -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-07-12 11:38:57.366580778 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 11:38:57.384437301 -0700 PDT [INFO] Found 1 running or paused containers 2017-07-12 11:38:57.523909752 -0700 PDT [INFO] Discovered 1 volumes in use. 2017-07-12 11:38:57.523951213 -0700 PDT [INFO] Volume name=restart_test_volume_353481@sharedVmfs-0 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-12 11:38:57.523961977 -0700 PDT [INFO] Refcounting successfully completed 2017-07-12 11:39:15.341272455 -0700 PDT [INFO] Mounting volume name="restart_test_volume_353481" 2017-07-12 11:39:15.439603315 -0700 PDT [INFO] Already mounted, skipping mount. refcount=2 name="restart_test_volume_353481@sharedVmfs-0" 2017-07-12 11:39:16.915726516 -0700 PDT [INFO] Mounting volume name="restart_test_volume_353481@sharedVmfs-0" 2017-07-12 11:39:16.9157618 -0700 PDT [INFO] Already mounted, skipping mount. refcount=3 name="restart_test_volume_353481@sharedVmfs-0" 2017-07-12 11:39:17.782925989 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_353481" 2017-07-12 11:39:17.782960906 -0700 PDT [INFO] Still in use, skipping unmount request. refcount=2 name="restart_test_volume_353481@sharedVmfs-0" 2017-07-12 11:39:17.838441447 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_353481" 2017-07-12 11:39:17.838487453 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_353481@sharedVmfs-0" refcount=1 2017-07-12 11:39:17.898165682 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_353481@sharedVmfs-0" 2017-07-12 11:39:21.56792698 -0700 PDT [INFO] Mounting volume name="restart_test_volume_353481" 2017-07-12 11:39:22.231835058 -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-07-12 11:39:27.420186879 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-12 11:39:29.576582868 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-12 11:39:29.576616799 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-12 11:39:29.577275211 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 11:39:29.592159222 -0700 PDT [INFO] Found 1 running or paused containers 2017-07-12 11:39:29.955969224 -0700 PDT [INFO] Discovered 1 volumes in use. 2017-07-12 11:39:29.956003188 -0700 PDT [INFO] Volume name=restart_test_volume_353481@sharedVmfs-0 count=1 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-12 11:39:29.956016036 -0700 PDT [INFO] Refcounting successfully completed 2017-07-12 11:39:29.956030145 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-12 11:39:29.956331281 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-12 11:39:40.441321705 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_353481" 2017-07-12 11:39:41.529893646 -0700 PDT [INFO] Mounting volume name="restart_test_volume_353481" 2017-07-12 11:39:42.075693053 -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-07-12 11:39:52.915806527 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_353481" 2017-07-12 11:39:57.063345989 -0700 PDT [INFO] Mounting volume name="restart_test_volume_353481" 2017-07-12 11:39:57.603612207 -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-07-12 11:39:58.583231097 -0700 PDT [INFO] Mounting volume name="restart_test_volume_353481" 2017-07-12 11:39:58.683600705 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_353481@sharedVmfs-0" refcount=2 2017-07-12 11:40:09.529939075 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_353481" 2017-07-12 11:40:09.529990742 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_353481@sharedVmfs-0" refcount=1 2017-07-12 11:40:09.583658648 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_353481" 2017-07-12 11:40:10.103989438 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-12 11:40:12.332371063 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-12 11:40:12.332430086 -0700 PDT [INFO] Starting plugin config="/etc/docker-volume-vsphere.conf" driver=vsphere log_level=info 2017-07-12 11:40:12.332611336 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 11:40:14.333195726 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-12 11:40:14.333330936 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-12 11:40:14.333357127 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-12 11:40:14.333504921 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-12 11:40:14.333799781 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-12 11:40:16.333880173 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 11:40:18.334112927 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-12 11:40:18.334176996 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). Attempts left: 20 2017-07-12 11:40:18.33418538 -0700 PDT [INFO] Scheduling again after 4 seconds 2017-07-12 11:40:18.940480627 -0700 PDT [INFO] Mounting volume name="restart_test_volume_353481" 2017-07-12 11:40:19.028432213 -0700 PDT [INFO] Mounting volume name="restart_test_volume_353481" 2017-07-12 11:40:19.651709435 -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-07-12 11:40:19.915910813 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_353481@sharedVmfs-0" 2017-07-12 11:40:22.334433697 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 11:40:22.372927144 -0700 PDT [INFO] Found 2 running or paused containers 2017-07-12 11:40:22.509330562 -0700 PDT [INFO] Discovered 1 volumes in use. 2017-07-12 11:40:22.509390097 -0700 PDT [INFO] Volume name=restart_test_volume_353481@sharedVmfs-0 count=2 mounted=true device='/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0' 2017-07-12 11:40:22.50939691 -0700 PDT [INFO] Refcounting successfully completed 2017-07-12 11:40:44.480527525 -0700 PDT [INFO] Mounting volume name="restart_test_volume_353481" 2017-07-12 11:40:44.575629458 -0700 PDT [INFO] Already mounted, skipping mount. name="restart_test_volume_353481@sharedVmfs-0" refcount=3 2017-07-12 11:40:45.443145168 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_353481" 2017-07-12 11:40:45.443183066 -0700 PDT [INFO] Still in use, skipping unmount request. refcount=2 name="restart_test_volume_353481@sharedVmfs-0" 2017-07-12 11:40:45.470680021 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_353481" 2017-07-12 11:40:45.470716067 -0700 PDT [INFO] Still in use, skipping unmount request. name="restart_test_volume_353481@sharedVmfs-0" refcount=1 2017-07-12 11:40:45.497055754 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_353481" 2017-07-12 11:40:51.9876887 -0700 PDT [INFO] Mounting volume name="restart_test_volume_353481" 2017-07-12 11:40:52.543616971 -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-07-12 11:41:07.301040245 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_353481" 2017-07-12 11:41:08.112097876 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-12 11:41:10.324857629 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-12 11:41:10.324893534 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-12 11:41:10.324914773 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 11:41:12.325698677 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-12 11:41:12.325748959 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-12 11:41:12.325767436 -0700 PDT [INFO] Docker VMDK plugin started mock_esx=false version="vSphere Volume Driver v0.5" port=1019 2017-07-12 11:41:12.326329531 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-12 11:41:12.326526097 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-12 11:41:14.326524993 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 11:41:16.328337237 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-12 11:41:16.328377125 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). Attempts left: 20 2017-07-12 11:41:16.328385817 -0700 PDT [INFO] Scheduling again after 4 seconds 2017-07-12 11:41:20.328602763 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-12 11:41:20.366442301 -0700 PDT [INFO] Found 0 running or paused containers 2017-07-12 11:41:20.367935519 -0700 PDT [INFO] Discovered 0 volumes in use. 2017-07-12 11:41:20.367948589 -0700 PDT [INFO] Refcounting successfully completed 2017-07-12 11:41:47.09512134 -0700 PDT [INFO] Mounting volume name="restart_test_volume_353481" 2017-07-12 11:41:47.631684994 -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-07-12 11:41:48.444583788 -0700 PDT [INFO] Unmounting Volume name="restart_test_volume_353481" 2017-07-12 11:41:49.872918083 -0700 PDT [INFO] Removing volume name="restart_test_volume_353481" 2017-07-12 11:42:05.351489566 -0700 PDT [INFO] Attaching volume and creating filesystem fstype=ext4 name="basicVGTest_volume_663340" 2017-07-12 11:42:05.975605174 -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-07-12 11:42:06.587521989 -0700 PDT [INFO] Volume and filesystem created fstype=ext4 name="basicVGTest_volume_663340" 2017-07-12 11:42:19.349178357 -0700 PDT [INFO] Removing volume name="basicVGTest_volume_663340" 2017-07-12 11:44:36.061094634 -0700 PDT [INFO] Removing volume name="VmGroupTest.TestVmGroupVolumeAccessAcrossVmGroups_volume_987388" 2017-07-12 11:47:04.415314291 -0700 PDT [INFO] Mounting volume name="vmlistener_test_volume_438932" 2017-07-12 11:47:04.995858859 -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-07-12 11:47:09.377313599 -0700 PDT [INFO] Unmounting Volume name="vmlistener_test_volume_438932" 2017-07-12 11:48:08.326005252 -0700 PDT [INFO] Mounting volume name="vmlistener_test_volume_234370@vsanDatastore" 2017-07-12 11:48:09.119746919 -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-07-12 11:48:13.463076616 -0700 PDT [INFO] Unmounting Volume name="vmlistener_test_volume_234370@vsanDatastore" 2017-07-17 15:36:28.687135884 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-17 15:39:56.34833963 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-17 15:39:56.348451613 -0700 PDT [INFO] Starting plugin log_level=info config="/etc/docker-volume-vsphere.conf" driver=vsphere 2017-07-17 15:39:56.348477744 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-17 15:39:56.369895753 -0700 PDT [INFO] Found 0 running or paused containers 2017-07-17 15:39:56.370111391 -0700 PDT [INFO] Discovered 0 volumes in use. 2017-07-17 15:39:56.370121683 -0700 PDT [INFO] Refcounting successfully completed 2017-07-17 15:39:56.370133472 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-17 15:39:56.370366744 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-17 15:52:58.06221854 -0700 PDT [INFO] Mounting volume name="swarm_test_volume_428012@sharedVmfs-0" 2017-07-17 15:52:58.785279475 -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-07-17 15:53:33.862032737 -0700 PDT [INFO] Unmounting Volume name="swarm_test_volume_428012@sharedVmfs-0" 2017-07-20 17:05:15.949686908 -0700 PDT [INFO] Removing volume name="sVmotionVol22@sharedVmfs-0" 2017-07-20 17:05:16.043579513 -0700 PDT [ERROR] Failed to remove volume error="Failed to remove volume sVmotionVol22, in use by VM = ubuntu-VM0.2." name="sVmotionVol22@sharedVmfs-0" 2017-07-20 17:10:07.837696286 -0700 PDT [INFO] Removing volume name="sVmotionVol22@sharedVmfs-0" 2017-07-20 17:10:30.655573997 -0700 PDT [INFO] Attaching volume and creating filesystem name=sVmotionVol22 fstype=ext4 2017-07-20 17:10:31.180062129 -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-07-20 17:10:31.835572132 -0700 PDT [INFO] Volume and filesystem created name=sVmotionVol22 fstype=ext4 2017-07-20 17:11:03.587476352 -0700 PDT [INFO] Attaching volume and creating filesystem name="sVmotionVol22@sharedVmfs-0" fstype= 2017-07-20 17:11:04.079611921 -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-07-20 17:12:20.051535049 -0700 PDT [INFO] Attaching volume and creating filesystem name="sVmotionVol2233@sharedVmfs-0" fstype= 2017-07-20 17:12:20.523662993 -0700 PDT [INFO] Scan complete device="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0" event="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:1:0": 0x100 == IN_CREATE 2017-07-20 17:13:02.139492401 -0700 PDT [INFO] Attaching volume and creating filesystem name="sVmotionVol33@sharedVmfs-0" fstype= 2017-07-20 17:13:02.671605643 -0700 PDT [INFO] Scan complete device="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:2:0" event="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:2:0": 0x100 == IN_CREATE 2017-07-20 17:31:22.579813169 -0700 PDT [INFO] Attaching volume and creating filesystem name="sVmotionVolXXXX@sharedVmfs-0" fstype= 2017-07-20 17:31:23.128111889 -0700 PDT [INFO] Scan complete device="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:3:0" event="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:3:0": 0x100 == IN_CREATE 2017-07-20 17:33:19.832775797 -0700 PDT [INFO] Mounting volume name="sVmotionVolXXXX@sharedVmfs-0" 2017-07-20 17:33:19.955747236 -0700 PDT [ERROR] name="sVmotionVolXXXX@sharedVmfs-0" error="Invalid filesystem type for sVmotionVolXXXX@sharedVmfs-0, assuming type as ext4." 2017-07-20 17:33:30.323999898 -0700 PDT [WARNING] Exceeded timeout while waiting for device attach to completedevice="/dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:3:0" timeout=10s 2017-07-20 17:33:30.325609807 -0700 PDT [ERROR] Failed to mount name="sVmotionVolXXXX@sharedVmfs-0" error="Failed to mount device /dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:3:0 at /mnt/vmdk/sVmotionVolXXXX@sharedVmfs-0: invalid argument" 2017-07-20 17:33:30.325640932 -0700 PDT [INFO] Detaching sVmotionVolXXXX@sharedVmfs-0 - it is not used anymore 2017-07-20 17:35:12.793225079 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-20 17:35:15.418161951 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-20 17:35:15.418275239 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-20 17:35:15.418518232 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-20 17:35:17.418881739 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-20 17:35:17.418924964 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). 2017-07-20 17:35:17.418941794 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-20 17:35:17.419408577 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-20 17:35:17.419555179 -0700 PDT [INFO] Scheduling again after 2 seconds 2017-07-20 17:35:19.419862634 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-20 17:35:21.420078111 -0700 PDT [INFO] Can't connect to unix:///var/run/docker.sock due to (An error occurred trying to connect: context deadline exceeded), skipping discovery 2017-07-20 17:35:21.420118958 -0700 PDT [INFO] Refcounting failed: (An error occurred trying to connect: context deadline exceeded). Attempts left: 20 2017-07-20 17:35:21.420136243 -0700 PDT [INFO] Scheduling again after 4 seconds 2017-07-20 17:35:25.420425484 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-20 17:35:25.43702904 -0700 PDT [INFO] Found 0 running or paused containers 2017-07-20 17:35:25.437216898 -0700 PDT [INFO] Discovered 0 volumes in use. 2017-07-20 17:35:25.437226685 -0700 PDT [INFO] Refcounting successfully completed 2017-07-20 17:39:41.826622972 -0700 PDT [INFO] Mounting volume name="sVmotionVol22@sharedVmfs-0" 2017-07-20 17:39:41.943961744 -0700 PDT [ERROR] name="sVmotionVol22@sharedVmfs-0" error="Invalid filesystem type for sVmotionVol22@sharedVmfs-0, assuming type as ext4." 2017-07-20 17:39:52.272162272 -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-07-20 17:39:52.280108184 -0700 PDT [ERROR] Failed to mount name="sVmotionVol22@sharedVmfs-0" error="Failed to mount device /dev/disk/by-path/pci-0000:03:00.0-scsi-0:0:0:0 at /mnt/vmdk/sVmotionVol22@sharedVmfs-0: invalid argument" 2017-07-20 17:39:52.280148469 -0700 PDT [INFO] Detaching sVmotionVol22@sharedVmfs-0 - it is not used anymore 2017-07-20 17:44:51.09469529 -0700 PDT [WARNING] Received signal signal=terminated 2017-07-20 17:45:08.089542852 -0700 PDT [INFO] No config file found. Using defaults. 2017-07-20 17:45:08.089805383 -0700 PDT [INFO] Starting plugin driver=vsphere log_level=info config="/etc/docker-volume-vsphere.conf" 2017-07-20 17:45:08.089846397 -0700 PDT [INFO] Getting volume data from unix:///var/run/docker.sock 2017-07-20 17:45:08.12256665 -0700 PDT [INFO] Found 0 running or paused containers 2017-07-20 17:45:08.122767976 -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\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/ingress_sbox nsfs rw 0 0\nnsfs /var/run/docker/netns/1-4cyfc4tux9 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-07-20 17:45:08.123023396 -0700 PDT [INFO] Successfully retrieved mountsmap=map[] 2017-07-20 17:45:08.123040542 -0700 PDT [INFO] Discovered 0 volumes in use. 2017-07-20 17:45:08.123045888 -0700 PDT [INFO] Refcounting successfully completed 2017-07-20 17:45:08.123054215 -0700 PDT [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.5" port=1019 mock_esx=false 2017-07-20 17:45:08.123127782 -0700 PDT [INFO] Going into ServeUnix - Listening on Unix socket address="/run/docker/plugins/vsphere.sock" 2017-07-20 17:45:33.377613041 -0700 PDT [INFO] Removing volume name="sVmotionVol2233@sharedVmfs-0" 2017-07-20 17:45:33.475507734 -0700 PDT [ERROR] Failed to remove volume name="sVmotionVol2233@sharedVmfs-0" error="Failed to remove volume sVmotionVol2233, in use by VM = ubuntu-VM2.2." 2017-07-20 17:45:33.948459076 -0700 PDT [INFO] Removing volume name="sVmotionVol22@sharedVmfs-0" 2017-07-20 17:45:34.407685985 -0700 PDT [INFO] Removing volume name="sVmotionVol22@sharedVmfs-1" 2017-07-20 17:45:34.891577315 -0700 PDT [INFO] Removing volume name="sVmotionVol33@sharedVmfs-0" 2017-07-20 17:45:34.991637775 -0700 PDT [ERROR] Failed to remove volume name="sVmotionVol33@sharedVmfs-0" error="Failed to remove volume sVmotionVol33, in use by VM = ubuntu-VM2.2." 2017-07-20 17:45:35.344471003 -0700 PDT [INFO] Removing volume name="sVmotionVolXXXX@sharedVmfs-0" 2017-07-20 17:49:52.023570077 -0700 PDT [INFO] Attaching volume and creating filesystem fstype= name="Vol22@sharedVmfs-0" 2017-07-20 17:49:52.531810723 -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