search

vmware / vic

vSphere Integrated Containers Engine is a container runtime for vSphere.
http://vmware.github.io/vic
Other
640 stars 173 forks source link

VCH's deploying but not finishing in reasonably-complex environment. #3264

Closed Chopper3 closed 7 years ago

Chopper3 commented 7 years ago

v 0.7.0

I'm an infrastructure guy at a large UK telco - we're very interested in VIC so I've been following its development and test deploying most major releases. 0.7.0 seems to do everything I need of it in my home lab (simple 1 x vCenter, 2 x host environment with no firewalls or proxies), so I decided to test deploying into one of our lab environments (1 x vCenter, 20 x HPE hosts all on 6.0u2). After a fair bit of faffing about with the cluster/port-group/storage pathing (see CormacH's recent blog post) I can now build VCHs - but they don't 'finish'.

Here's the output of a 'create' using --debug;

root@rm101vicc [ ~/vic ]# ./vic-machine-linux create  --target 'rm101vcenter.room101.com' --user vicadmin@vsphere.local --password notactualpassword --compute-resource '/Room101/host/Main-Cluster/Resources/vSphere Integrated Containers/VCHs' --thumbprint D1:D5:00:99:80:28:51:7D:BB:A2:03:8D:7A:5E:7D:83:1E:B9:45:51 --no-tlsverify  --insecure-registry http://rm101harbor.room101.com --image-store 'NotMe-rm101nas01-vms/vSphere Integrated Containers - ImageStore/rm101vch4050' --volume-store 'NotMe-rm101nas01-vms/vSphere Integrated Containers - VolumeStore/rm101vch4050:rm101vch4050' --bridge-network '/Room101/network/VOSP Networks/rm101vch4050' --bridge-network-range '192.168.100.0/24' --external-network '/Room101/network/VOSP Networks/vSphere Integrated Containers' --external-network-ip '10.101.33.50/24' --external-network-gateway '10.101.33.1/24' --name 'rm101vch4050' --dns-server=10.101.5.7 --dns-server=10.101.32.137 --http-proxy http://proxy.room101.com:8080 --https-proxy https://proxy.room101.com:8080 --timeout '10m0s' --debug 1
time=2016-11-17T14:52:41.623946876Z level=debug msg=[BEGIN] [github.com/vmware/vic/cmd/vic-machine/create.(*Create).processParams:455]
DEBU[2016-11-17T14:52:41Z] external network: IP {"10.101.33.50" "ffffff00"} gateway {"10.101.33.1" "ffffff00"}
DEBU[2016-11-17T14:52:41Z] VCH DNS servers: [10.101.5.7 10.101.32.137]
time=2016-11-17T14:52:41.624256868Z level=debug msg=[BEGIN] [github.com/vmware/vic/cmd/vic-machine/create.(*Create).loadCertificates:782]
time=2016-11-17T14:52:41.624287687Z level=debug msg=[ END ] [github.com/vmware/vic/cmd/vic-machine/create.(*Create).loadCertificates:782] [29.596µs]
time=2016-11-17T14:52:41.624332410Z level=debug msg=[BEGIN] [github.com/vmware/vic/cmd/vic-machine/create.(*Create).generateCertificates:815]
INFO[2016-11-17T14:52:41Z] Generating self-signed certificate/key pair - private key in ./rm101vch4050/key.pem
time=2016-11-17T14:52:41.624489239Z level=debug msg=[BEGIN] [github.com/vmware/vic/pkg/certificate.CreateSelfSigned:251]
time=2016-11-17T14:52:41.892337750Z level=debug msg=[BEGIN] [github.com/vmware/vic/pkg/certificate.createCertificate:148]
time=2016-11-17T14:52:41.896256832Z level=debug msg=[ END ] [github.com/vmware/vic/pkg/certificate.createCertificate:148] [3.921139ms]
time=2016-11-17T14:52:41.896320226Z level=debug msg=[ END ] [github.com/vmware/vic/pkg/certificate.CreateSelfSigned:251] [271.824032ms]
time=2016-11-17T14:52:41.896362411Z level=debug msg=[ END ] [github.com/vmware/vic/cmd/vic-machine/create.(*Create).generateCertificates:815] [272.028536ms]
WARN[2016-11-17T14:52:41Z] Configuring without TLS verify - client authentication disabled
time=2016-11-17T14:52:41.896457804Z level=debug msg=[BEGIN] [github.com/vmware/vic/cmd/vic-machine/create.(*Create).processVolumeStores:737]
time=2016-11-17T14:52:41.896512484Z level=debug msg=[ END ] [github.com/vmware/vic/cmd/vic-machine/create.(*Create).processVolumeStores:737] [53.963µs]
time=2016-11-17T14:52:41.896562113Z level=debug msg=[ END ] [github.com/vmware/vic/cmd/vic-machine/create.(*Create).processParams:455] [272.616665ms]
time=2016-11-17T14:52:41.896614243Z level=debug msg=[BEGIN] [github.com/vmware/vic/cmd/vic-machine/common.(*Images).CheckImagesFiles:77]
time=2016-11-17T14:52:41.896709730Z level=debug msg=[BEGIN] [github.com/vmware/vic/cmd/vic-machine/common.(*Images).checkImageVersion:162]
time=2016-11-17T14:52:41.896759853Z level=debug msg=[BEGIN] [github.com/vmware/vic/cmd/vic-machine/common.(*Images).GetImageVersion:133]
time=2016-11-17T14:52:41.896823862Z level=debug msg=[ END ] [github.com/vmware/vic/cmd/vic-machine/common.(*Images).GetImageVersion:133] [63.442µs]
time=2016-11-17T14:52:41.896863612Z level=debug msg=[BEGIN] [github.com/vmware/vic/cmd/vic-machine/common.(*Images).getNoCommitHashVersion:188]
time=2016-11-17T14:52:41.896888656Z level=debug msg=[ END ] [github.com/vmware/vic/cmd/vic-machine/common.(*Images).getNoCommitHashVersion:188] [22.78µs]
time=2016-11-17T14:52:41.896922695Z level=debug msg=[BEGIN] [github.com/vmware/vic/cmd/vic-machine/common.(*Images).getNoCommitHashVersion:188]
time=2016-11-17T14:52:41.896948247Z level=debug msg=[ END ] [github.com/vmware/vic/cmd/vic-machine/common.(*Images).getNoCommitHashVersion:188] [24.589µs]
time=2016-11-17T14:52:41.896967231Z level=debug msg=[ END ] [github.com/vmware/vic/cmd/vic-machine/common.(*Images).checkImageVersion:162] [301.998µs]
time=2016-11-17T14:52:41.897021185Z level=debug msg=[BEGIN] [github.com/vmware/vic/cmd/vic-machine/common.(*Images).checkImageVersion:162]
time=2016-11-17T14:52:41.897059337Z level=debug msg=[BEGIN] [github.com/vmware/vic/cmd/vic-machine/common.(*Images).GetImageVersion:133]
time=2016-11-17T14:52:41.897093997Z level=debug msg=[ END ] [github.com/vmware/vic/cmd/vic-machine/common.(*Images).GetImageVersion:133] [44.73µs]
time=2016-11-17T14:52:41.897141049Z level=debug msg=[BEGIN] [github.com/vmware/vic/cmd/vic-machine/common.(*Images).getNoCommitHashVersion:188]
time=2016-11-17T14:52:41.897180780Z level=debug msg=[ END ] [github.com/vmware/vic/cmd/vic-machine/common.(*Images).getNoCommitHashVersion:188] [38.517µs]
time=2016-11-17T14:52:41.897208242Z level=debug msg=[BEGIN] [github.com/vmware/vic/cmd/vic-machine/common.(*Images).getNoCommitHashVersion:188]
time=2016-11-17T14:52:41.897239385Z level=debug msg=[ END ] [github.com/vmware/vic/cmd/vic-machine/common.(*Images).getNoCommitHashVersion:188] [29.303µs]
time=2016-11-17T14:52:41.897261607Z level=debug msg=[ END ] [github.com/vmware/vic/cmd/vic-machine/common.(*Images).checkImageVersion:162] [239.763µs]
time=2016-11-17T14:52:41.897287844Z level=debug msg=[ END ] [github.com/vmware/vic/cmd/vic-machine/common.(*Images).CheckImagesFiles:77] [671.031µs]
INFO[2016-11-17T14:52:41Z] ### Installing VCH ####
time=2016-11-17T14:52:41.897392864Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.CreateNoDCCheck:80]
DEBU[2016-11-17T14:52:41Z] Using to login by username/password
DEBU[2016-11-17T14:52:42Z] Session Environment Info:                     API Type=VirtualCenter API Version=6.0 Build=3634794 Name=VMware vCenter Server OS Type=linux-x64 Product ID=vpx UUID=4f14e124-d8f9-4f57-a354-0197f9c9f3b6 Vendor=VMware, Inc. Version=6.0.0
DEBU[2016-11-17T14:52:42Z] vSphere resource cache populating...
DEBU[2016-11-17T14:52:42Z] Cached dc:
DEBU[2016-11-17T14:52:42Z] Error count populating vSphere cache: (3)
time=2016-11-17T14:52:42.084490790Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.CreateNoDCCheck:80] [187.090758ms]
time=2016-11-17T14:52:42.084614691Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).Validate:231]
INFO[2016-11-17T14:52:42Z] Validating supplied configuration
time=2016-11-17T14:52:42.084893113Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).basics:267]
DEBU[2016-11-17T14:52:42Z] Setting scratch image size to 8000000 KB in VCHConfig
time=2016-11-17T14:52:42.085121330Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).basics:267] [224.51µs]
time=2016-11-17T14:52:42.085233897Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).target:311]
time=2016-11-17T14:52:42.085353776Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).managedbyVC:337]
time=2016-11-17T14:52:42.085474521Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).managedbyVC:337] [117.389µs]
time=2016-11-17T14:52:42.085562210Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).target:311] [333.753µs]
time=2016-11-17T14:52:42.085649618Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).compute:36]
time=2016-11-17T14:52:42.085759408Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).ResourcePoolHelper:78] /Room101/host/Main-Cluster/Resources/vSphere Integrated Containers/VCHs
time=2016-11-17T14:52:42.085831396Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).computePathToInventoryPath:513] /Room101/host/Main-Cluster/Resources/vSphere Integrated Containers/VCHs
DEBU[2016-11-17T14:52:42Z] Path is treated as absolute given datacenter prefix "/Room101"
time=2016-11-17T14:52:42.085908572Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).computePathToInventoryPath:513] [73.473µs] /Room101/host/Main-Cluster/Resources/vSphere Integrated Containers/VCHs
DEBU[2016-11-17T14:52:42Z] Converted original path "/Room101/host/Main-Cluster/Resources/vSphere Integrated Containers/VCHs" to "/Room101/host/Main-Cluster/Resources/vSphere Integrated Containers/VCHs"
DEBU[2016-11-17T14:52:42Z] Selected compute resource "/Room101/host/Main-Cluster/Resources/vSphere Integrated Containers/VCHs"
time=2016-11-17T14:52:42.097924900Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).ResourcePoolHelper:78] [12.16821ms] /Room101/host/Main-Cluster/Resources/vSphere Integrated Containers/VCHs
time=2016-11-17T14:52:42.097969959Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).inventoryPathToCluster:582] /Room101/host/Main-Cluster/Resources/vSphere Integrated Containers/VCHs
time=2016-11-17T14:52:42.098018115Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).inventoryPathToCluster:582] [47.357µs] /Room101/host/Main-Cluster/Resources/vSphere Integrated Containers/VCHs
time=2016-11-17T14:52:42.103399676Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).compute:36] [17.751294ms]
time=2016-11-17T14:52:42.103462897Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).storage:34]
time=2016-11-17T14:52:42.103506772Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).DatastoreHelper:70] NotMe-rm101nas01-vms/vSphere Integrated Containers - ImageStore/rm101vch4050
time=2016-11-17T14:52:42.106903496Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).DatastoreHelper:70] [3.406007ms] NotMe-rm101nas01-vms/vSphere Integrated Containers - ImageStore/rm101vch4050
time=2016-11-17T14:52:42.106963805Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).DatastoreHelper:70] NotMe-rm101nas01-vms/vSphere Integrated Containers - VolumeStore/rm101vch4050
time=2016-11-17T14:52:42.110561161Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).DatastoreHelper:70] [3.600339ms] NotMe-rm101nas01-vms/vSphere Integrated Containers - VolumeStore/rm101vch4050
time=2016-11-17T14:52:42.110702374Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).storage:34] [7.20672ms]
time=2016-11-17T14:52:42.110815055Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).network:168]
time=2016-11-17T14:52:42.110914379Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).portGroupConfig:86]
time=2016-11-17T14:52:42.111003359Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).portGroupConfig:86] [87.101µs]
time=2016-11-17T14:52:42.111087132Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).checkPortGroups:112]
time=2016-11-17T14:52:42.111202139Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).checkPortGroups:112] [113.469µs]
time=2016-11-17T14:52:42.111304301Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).configureSharedPortGroups:145]
INFO[2016-11-17T14:52:42Z] Configuring static IP for additional networks using port group "/Room101/network/VOSP Networks/vSphere Integrated Containers"
time=2016-11-17T14:52:42.111514812Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).configureSharedPortGroups:145] [200.568µs]
time=2016-11-17T14:52:42.111612476Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).getEndpoint:39]
DEBU[2016-11-17T14:52:42Z] Setting static IP for "external" on port group "/Room101/network/VOSP Networks/vSphere Integrated Containers"
time=2016-11-17T14:52:42.111860788Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).networkHelper:406] /Room101/network/VOSP Networks/vSphere Integrated Containers
time=2016-11-17T14:52:42.111977298Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).getNetwork:388] /Room101/network/VOSP Networks/vSphere Integrated Containers
time=2016-11-17T14:52:42.122800960Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).getNetwork:388] [10.833191ms] /Room101/network/VOSP Networks/vSphere Integrated Containers
time=2016-11-17T14:52:42.122868778Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).networkHelper:406] [11.001674ms] /Room101/network/VOSP Networks/vSphere Integrated Containers
DEBU[2016-11-17T14:52:42Z] NetworkEndpoint: &{{  external } true 10.101.33.50/24 {<nil> <nil>} {{ DistributedVirtualPortgroup:dvportgroup-1761 external }  {10.101.33.1 ffffff00} true [10.101.5.7 10.101.32.137] [] []} []}
time=2016-11-17T14:52:42.123003955Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).getEndpoint:39] [11.392497ms]
time=2016-11-17T14:52:42.123059955Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).getEndpoint:39]
DEBU[2016-11-17T14:52:42Z] Setting static IP for "client" on port group "/Room101/network/VOSP Networks/vSphere Integrated Containers"
time=2016-11-17T14:52:42.123174608Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).networkHelper:406] /Room101/network/VOSP Networks/vSphere Integrated Containers
time=2016-11-17T14:52:42.123222446Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).getNetwork:388] /Room101/network/VOSP Networks/vSphere Integrated Containers
time=2016-11-17T14:52:42.138050251Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).getNetwork:388] [14.821055ms] /Room101/network/VOSP Networks/vSphere Integrated Containers
time=2016-11-17T14:52:42.138182374Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).networkHelper:406] [15.002023ms] /Room101/network/VOSP Networks/vSphere Integrated Containers
DEBU[2016-11-17T14:52:42Z] NetworkEndpoint: &{{  client } true 10.101.33.50/24 {<nil> <nil>} {{ DistributedVirtualPortgroup:dvportgroup-1761 client }  {10.101.33.1 ffffff00} false [10.101.5.7 10.101.32.137] [] []} []}
time=2016-11-17T14:52:42.138479295Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).getEndpoint:39] [15.412106ms]
time=2016-11-17T14:52:42.138588641Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).getEndpoint:39]
DEBU[2016-11-17T14:52:42Z] Setting static IP for "management" on port group "/Room101/network/VOSP Networks/vSphere Integrated Containers"
time=2016-11-17T14:52:42.138809209Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).networkHelper:406] /Room101/network/VOSP Networks/vSphere Integrated Containers
time=2016-11-17T14:52:42.138904302Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).getNetwork:388] /Room101/network/VOSP Networks/vSphere Integrated Containers
time=2016-11-17T14:52:42.157170554Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).getNetwork:388] [18.266683ms] /Room101/network/VOSP Networks/vSphere Integrated Containers
time=2016-11-17T14:52:42.157243089Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).networkHelper:406] [18.431636ms] /Room101/network/VOSP Networks/vSphere Integrated Containers
DEBU[2016-11-17T14:52:42Z] NetworkEndpoint: &{{   } true 10.101.33.50/24 {<nil> <nil>} {{ DistributedVirtualPortgroup:dvportgroup-1761 management }  {10.101.33.1 ffffff00} false [10.101.5.7 10.101.32.137] [] []} []}
time=2016-11-17T14:52:42.157357144Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).getEndpoint:39] [18.769454ms]
DEBU[2016-11-17T14:52:42Z] Network configuration:
DEBU[2016-11-17T14:52:42Z]      Network: external NetworkEndpoint: &{{  external } true 10.101.33.50/24 {<nil> <nil>} {{ DistributedVirtualPortgroup:dvportgroup-1761 external }  {10.101.33.1 ffffff00} true [10.101.5.7 10.101.32.137] [] []} []}
DEBU[2016-11-17T14:52:42Z]      Network: client NetworkEndpoint: &{{  client } true 10.101.33.50/24 {<nil> <nil>} {{ DistributedVirtualPortgroup:dvportgroup-1761 client }  {10.101.33.1 ffffff00} false [10.101.5.7 10.101.32.137] [] []} []}
DEBU[2016-11-17T14:52:42Z]      Network: management NetworkEndpoint: &{{   } true 10.101.33.50/24 {<nil> <nil>} {{ DistributedVirtualPortgroup:dvportgroup-1761 management }  {10.101.33.1 ffffff00} false [10.101.5.7 10.101.32.137] [] []} []}
time=2016-11-17T14:52:42.157675630Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).dpgHelper:445] /Room101/network/VOSP Networks/rm101vch4050
time=2016-11-17T14:52:42.157716346Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).getNetwork:388] /Room101/network/VOSP Networks/rm101vch4050
time=2016-11-17T14:52:42.167375117Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).getNetwork:388] [9.656644ms] /Room101/network/VOSP Networks/rm101vch4050
time=2016-11-17T14:52:42.167433713Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).dpgHelper:445] [9.756778ms] /Room101/network/VOSP Networks/rm101vch4050
time=2016-11-17T14:52:42.167475600Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).checkVDSMembership:478] dvportgroup-1757
time=2016-11-17T14:52:42.174464591Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466]
time=2016-11-17T14:52:42.174533283Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466] [67.081µs]
time=2016-11-17T14:52:42.174575095Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466]
time=2016-11-17T14:52:42.174632534Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466] [57.303µs]
time=2016-11-17T14:52:42.174668165Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466]
time=2016-11-17T14:52:42.174700874Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466] [23.551µs]
time=2016-11-17T14:52:42.174724722Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466]
time=2016-11-17T14:52:42.174761216Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466] [35.223µs]
time=2016-11-17T14:52:42.174792268Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466]
time=2016-11-17T14:52:42.174828359Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466] [34.918µs]
time=2016-11-17T14:52:42.174856497Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466]
time=2016-11-17T14:52:42.174907772Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466] [49.58µs]
time=2016-11-17T14:52:42.174968136Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466]
time=2016-11-17T14:52:42.175005309Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466] [36.51µs]
time=2016-11-17T14:52:42.175046680Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466]
time=2016-11-17T14:52:42.175082439Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466] [35.18µs]
time=2016-11-17T14:52:42.175131389Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466]
time=2016-11-17T14:52:42.175168993Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466] [37.172µs]
time=2016-11-17T14:52:42.175215153Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466]
time=2016-11-17T14:52:42.175240106Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466] [24.498µs]
time=2016-11-17T14:52:42.175304622Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466]
time=2016-11-17T14:52:42.175354831Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466] [50.38µs]
time=2016-11-17T14:52:42.175406660Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466]
time=2016-11-17T14:52:42.175453778Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466] [45.414µs]
time=2016-11-17T14:52:42.175504422Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466]
time=2016-11-17T14:52:42.175543429Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466] [39.541µs]
time=2016-11-17T14:52:42.175604108Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466]
time=2016-11-17T14:52:42.175646905Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466] [52.785µs]
time=2016-11-17T14:52:42.175685189Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466]
time=2016-11-17T14:52:42.175733376Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466] [47.385µs]
time=2016-11-17T14:52:42.175772161Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466]
time=2016-11-17T14:52:42.175796233Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466] [24.078µs]
time=2016-11-17T14:52:42.175842398Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466]
time=2016-11-17T14:52:42.175869440Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466] [34.315µs]
time=2016-11-17T14:52:42.175919634Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466]
time=2016-11-17T14:52:42.175965914Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).inDVP:466] [52.816µs]
INFO[2016-11-17T14:52:42Z] vDS configuration OK on "/Room101/network/VOSP Networks/rm101vch4050"
time=2016-11-17T14:52:42.176049758Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).checkVDSMembership:478] [8.573357ms] dvportgroup-1757
time=2016-11-17T14:52:42.176101529Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).nicNumbers:369]
time=2016-11-17T14:52:42.176140048Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).nicNumbers:369] [27.942µs]
time=2016-11-17T14:52:42.176181421Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).network:168] [65.368267ms]
time=2016-11-17T14:52:42.176240735Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).CheckFirewall:37]
INFO[2016-11-17T14:52:42Z] Firewall status: ENABLED on "/Room101/host/Main-Cluster/rm101enc01bl02.room101.com"
INFO[2016-11-17T14:52:42Z] Firewall status: ENABLED on "/Room101/host/Main-Cluster/rm101enc01bl12.room101.com"
INFO[2016-11-17T14:52:42Z] Firewall status: ENABLED on "/Room101/host/Main-Cluster/rm101enc02bl09.room101.com"
INFO[2016-11-17T14:52:42Z] Firewall status: ENABLED on "/Room101/host/Main-Cluster/rm101enc02bl10.room101.com"
INFO[2016-11-17T14:52:42Z] Firewall status: ENABLED on "/Room101/host/Main-Cluster/rm101enc01bl11.room101.com"
INFO[2016-11-17T14:52:42Z] Firewall status: ENABLED on "/Room101/host/Main-Cluster/rm101enc01bl03.room101.com"
INFO[2016-11-17T14:52:42Z] Firewall status: ENABLED on "/Room101/host/Main-Cluster/rm101enc01bl04.room101.com"
INFO[2016-11-17T14:52:42Z] Firewall status: ENABLED on "/Room101/host/Main-Cluster/rm101enc01bl09.room101.com"
INFO[2016-11-17T14:52:42Z] Firewall status: ENABLED on "/Room101/host/Main-Cluster/rm101enc01bl10.room101.com"
INFO[2016-11-17T14:52:42Z] Firewall status: ENABLED on "/Room101/host/Main-Cluster/rm101enc02bl01.room101.com"
INFO[2016-11-17T14:52:42Z] Firewall status: ENABLED on "/Room101/host/Main-Cluster/rm101enc02bl02.room101.com"
INFO[2016-11-17T14:52:42Z] Firewall status: ENABLED on "/Room101/host/Main-Cluster/rm101enc02bl03.room101.com"
INFO[2016-11-17T14:52:42Z] Firewall status: ENABLED on "/Room101/host/Main-Cluster/rm101enc02bl04.room101.com"
INFO[2016-11-17T14:52:42Z] Firewall status: ENABLED on "/Room101/host/Main-Cluster/rm101enc02bl05.room101.com"
INFO[2016-11-17T14:52:42Z] Firewall status: ENABLED on "/Room101/host/Main-Cluster/rm101enc02bl06.room101.com"
INFO[2016-11-17T14:52:42Z] Firewall status: ENABLED on "/Room101/host/Main-Cluster/rm101enc01bl01.room101.com"
INFO[2016-11-17T14:52:42Z] Firewall status: ENABLED on "/Room101/host/Main-Cluster/rm101enc02bl07.room101.com"
INFO[2016-11-17T14:52:42Z] Firewall status: ENABLED on "/Room101/host/Main-Cluster/rm101enc02bl08.room101.com"
INFO[2016-11-17T14:52:42Z] Firewall configuration OK on hosts:
INFO[2016-11-17T14:52:42Z]   "/Room101/host/Main-Cluster/rm101enc01bl02.room101.com"
INFO[2016-11-17T14:52:42Z]   "/Room101/host/Main-Cluster/rm101enc01bl12.room101.com"
INFO[2016-11-17T14:52:42Z]   "/Room101/host/Main-Cluster/rm101enc02bl09.room101.com"
INFO[2016-11-17T14:52:42Z]   "/Room101/host/Main-Cluster/rm101enc02bl10.room101.com"
INFO[2016-11-17T14:52:42Z]   "/Room101/host/Main-Cluster/rm101enc01bl11.room101.com"
INFO[2016-11-17T14:52:42Z]   "/Room101/host/Main-Cluster/rm101enc01bl03.room101.com"
INFO[2016-11-17T14:52:42Z]   "/Room101/host/Main-Cluster/rm101enc01bl04.room101.com"
INFO[2016-11-17T14:52:42Z]   "/Room101/host/Main-Cluster/rm101enc01bl09.room101.com"
INFO[2016-11-17T14:52:42Z]   "/Room101/host/Main-Cluster/rm101enc01bl10.room101.com"
INFO[2016-11-17T14:52:42Z]   "/Room101/host/Main-Cluster/rm101enc02bl01.room101.com"
INFO[2016-11-17T14:52:42Z]   "/Room101/host/Main-Cluster/rm101enc02bl02.room101.com"
INFO[2016-11-17T14:52:42Z]   "/Room101/host/Main-Cluster/rm101enc02bl03.room101.com"
INFO[2016-11-17T14:52:42Z]   "/Room101/host/Main-Cluster/rm101enc02bl04.room101.com"
INFO[2016-11-17T14:52:42Z]   "/Room101/host/Main-Cluster/rm101enc02bl05.room101.com"
INFO[2016-11-17T14:52:42Z]   "/Room101/host/Main-Cluster/rm101enc02bl06.room101.com"
INFO[2016-11-17T14:52:42Z]   "/Room101/host/Main-Cluster/rm101enc01bl01.room101.com"
INFO[2016-11-17T14:52:42Z]   "/Room101/host/Main-Cluster/rm101enc02bl07.room101.com"
INFO[2016-11-17T14:52:42Z]   "/Room101/host/Main-Cluster/rm101enc02bl08.room101.com"
time=2016-11-17T14:52:42.996739075Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).CheckFirewall:37] [820.494291ms]
INFO[2016-11-17T14:52:43Z] License check OK on hosts:
INFO[2016-11-17T14:52:43Z]   "/Room101/host/Main-Cluster/rm101enc01bl02.room101.com"
INFO[2016-11-17T14:52:43Z]   "/Room101/host/Main-Cluster/rm101enc01bl12.room101.com"
INFO[2016-11-17T14:52:43Z]   "/Room101/host/Main-Cluster/rm101enc02bl09.room101.com"
INFO[2016-11-17T14:52:43Z]   "/Room101/host/Main-Cluster/rm101enc02bl10.room101.com"
INFO[2016-11-17T14:52:43Z]   "/Room101/host/Main-Cluster/rm101enc01bl11.room101.com"
INFO[2016-11-17T14:52:43Z]   "/Room101/host/Main-Cluster/rm101enc01bl03.room101.com"
INFO[2016-11-17T14:52:43Z]   "/Room101/host/Main-Cluster/rm101enc01bl04.room101.com"
INFO[2016-11-17T14:52:43Z]   "/Room101/host/Main-Cluster/rm101enc01bl09.room101.com"
INFO[2016-11-17T14:52:43Z]   "/Room101/host/Main-Cluster/rm101enc01bl10.room101.com"
INFO[2016-11-17T14:52:43Z]   "/Room101/host/Main-Cluster/rm101enc02bl01.room101.com"
INFO[2016-11-17T14:52:43Z]   "/Room101/host/Main-Cluster/rm101enc02bl02.room101.com"
INFO[2016-11-17T14:52:43Z]   "/Room101/host/Main-Cluster/rm101enc02bl03.room101.com"
INFO[2016-11-17T14:52:43Z]   "/Room101/host/Main-Cluster/rm101enc02bl04.room101.com"
INFO[2016-11-17T14:52:43Z]   "/Room101/host/Main-Cluster/rm101enc02bl05.room101.com"
INFO[2016-11-17T14:52:43Z]   "/Room101/host/Main-Cluster/rm101enc02bl06.room101.com"
INFO[2016-11-17T14:52:43Z]   "/Room101/host/Main-Cluster/rm101enc01bl01.room101.com"
INFO[2016-11-17T14:52:43Z]   "/Room101/host/Main-Cluster/rm101enc02bl07.room101.com"
INFO[2016-11-17T14:52:43Z]   "/Room101/host/Main-Cluster/rm101enc02bl08.room101.com"
time=2016-11-17T14:52:43.720368445Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).CheckDrs:273]
INFO[2016-11-17T14:52:43Z] DRS check OK on:
INFO[2016-11-17T14:52:43Z]   "/Room101/host/Main-Cluster/Resources/vSphere Integrated Containers/VCHs"
time=2016-11-17T14:52:43.725409691Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).CheckDrs:273] [5.04694ms]
time=2016-11-17T14:52:43.725461903Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).certificate:362]
time=2016-11-17T14:52:43.726107253Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).certificate:362] [644.029µs]
time=2016-11-17T14:52:43.726172053Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).certificateAuthorities:381]
DEBU[2016-11-17T14:52:43Z] Configuring without client verification due to empty certificate authorities
time=2016-11-17T14:52:43.726275320Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).certificateAuthorities:381] [102.358µs]
time=2016-11-17T14:52:43.726320156Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).compatibility:406]
time=2016-11-17T14:52:43.778830788Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).checkDatastoresAreWriteable:457]
time=2016-11-17T14:52:43.841104490Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).checkDatastoresAreWriteable:457] [62.271369ms]
time=2016-11-17T14:52:43.841274747Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).compatibility:406] [114.947631ms]
time=2016-11-17T14:52:43.841387867Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).ListIssues:206]
time=2016-11-17T14:52:43.841486562Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).ListIssues:206] [96.895µs]
time=2016-11-17T14:52:43.841605302Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).Validate:231] [1.756980934s]
time=2016-11-17T14:52:43.841701530Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/validate.(*Validator).AddDeprecatedFields:601]
DEBU[2016-11-17T14:52:43Z] Datacenter: "Room101", Cluster: "/Room101/host/Main-Cluster", Resource Pool: "/Room101/host/Main-Cluster/Resources/vSphere Integrated Containers/VCHs"
time=2016-11-17T14:52:43.841979252Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/validate.(*Validator).AddDeprecatedFields:601] [273.551µs]
time=2016-11-17T14:52:43.842114425Z level=debug msg=[BEGIN] [github.com/vmware/vic/pkg/certificate.CreateSelfSigned:251]
time=2016-11-17T14:52:44.080867328Z level=debug msg=[BEGIN] [github.com/vmware/vic/pkg/certificate.createCertificate:148]
time=2016-11-17T14:52:44.085224843Z level=debug msg=[ END ] [github.com/vmware/vic/pkg/certificate.createCertificate:148] [4.362158ms]
time=2016-11-17T14:52:44.085305547Z level=debug msg=[ END ] [github.com/vmware/vic/pkg/certificate.CreateSelfSigned:251] [243.189737ms]
INFO[2016-11-17T14:52:44Z]
time=2016-11-17T14:52:44.085460132Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.NewDispatcher:78]
time=2016-11-17T14:52:44.085537061Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).InitDiagnosticLogs:95]
time=2016-11-17T14:52:46.817712154Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).InitDiagnosticLogs:95] [2.732165985s]
time=2016-11-17T14:52:46.817835037Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.NewDispatcher:78] [2.732373903s]
time=2016-11-17T14:52:46.817917611Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).CreateVCH:37] rm101vch4050
time=2016-11-17T14:52:46.817960749Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).checkExistence:93]
time=2016-11-17T14:52:46.818026571Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).findVirtualApp:107] /Room101/host/Main-Cluster/Resources/vSphere Integrated Containers/VCHs/rm101vch4050
time=2016-11-17T14:52:46.832672591Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).findVirtualApp:107] [14.646942ms] /Room101/host/Main-Cluster/Resources/vSphere Integrated Containers/VCHs/rm101vch4050
time=2016-11-17T14:52:46.832735354Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).findResourcePool:133] /Room101/host/Main-Cluster/Resources/vSphere Integrated Containers/VCHs/rm101vch4050
time=2016-11-17T14:52:46.845384418Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).findResourcePool:133] [12.635167ms] /Room101/host/Main-Cluster/Resources/vSphere Integrated Containers/VCHs/rm101vch4050
time=2016-11-17T14:52:46.845435096Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).checkExistence:93] [27.472761ms]
time=2016-11-17T14:52:46.845492550Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).createVApp:31]
INFO[2016-11-17T14:52:46Z] Creating virtual app "rm101vch4050"
time=2016-11-17T14:52:46.871374436Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).createVApp:31] [25.861446ms]
time=2016-11-17T14:52:46.871524150Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).createBridgeNetwork:28]
time=2016-11-17T14:52:46.871639937Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).createBridgeNetwork:28] [114.142µs]
time=2016-11-17T14:52:46.871754580Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).createVolumeStores:270]
INFO[2016-11-17T14:52:46Z] Creating directory [NotMe-rm101nas01-vms] vSphere Integrated Containers - VolumeStore/rm101vch4050
INFO[2016-11-17T14:52:46Z] Datastore path is [NotMe-rm101nas01-vms] vSphere Integrated Containers - VolumeStore/rm101vch4050
time=2016-11-17T14:52:46.884030430Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).createVolumeStores:270] [12.277344ms]
time=2016-11-17T14:52:46.884083222Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).createAppliance:405]
INFO[2016-11-17T14:52:46Z] Creating appliance on target
time=2016-11-17T14:52:46.884158713Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).createApplianceSpec:289]
DEBU[2016-11-17T14:52:46Z] generating new config secret key
time=2016-11-17T14:52:46.884950825Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).addIDEController:265]
time=2016-11-17T14:52:46.884997813Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).addIDEController:265] [44.618µs]
time=2016-11-17T14:52:46.885046506Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).addParaVirtualSCSIController:277]
time=2016-11-17T14:52:46.887289015Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).addParaVirtualSCSIController:277] [2.236207ms]
time=2016-11-17T14:52:46.887359855Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).addNetworkDevices:209]
DEBU[2016-11-17T14:52:46Z] Setting "bridge" to slot 192
DEBU[2016-11-17T14:52:46Z] Setting "external" to slot 224
INFO[2016-11-17T14:52:46Z] Network role "client" is sharing NIC with "external"
INFO[2016-11-17T14:52:46Z] Network role "management" is sharing NIC with "external"
time=2016-11-17T14:52:46.897134475Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).addNetworkDevices:209] [9.773444ms]
time=2016-11-17T14:52:46.897171031Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).createApplianceSpec:289] [13.011469ms]
DEBU[2016-11-17T14:52:57Z] vm folder name: "rm101vch4050"
DEBU[2016-11-17T14:52:57Z] vm inventory path: "/"
time=2016-11-17T14:52:57.762051770Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).GenerateExtensionName:366]
time=2016-11-17T14:52:57.763917622Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).GenerateExtensionName:366] [1.863777ms]
time=2016-11-17T14:52:57.763989495Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).reconfigureApplianceSpec:598]
time=2016-11-17T14:52:57.764020397Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).configIso:379]
time=2016-11-17T14:52:57.766963846Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).configIso:379] [2.941772ms]
time=2016-11-17T14:52:57.767904284Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).reconfigureApplianceSpec:598] [3.912776ms]
time=2016-11-17T14:52:58.308283853Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).createAppliance:405] [11.424196111s]
time=2016-11-17T14:52:58.308387411Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).uploadImages:115]
INFO[2016-11-17T14:52:58Z] Uploading images for container
INFO[2016-11-17T14:52:58Z]      "appliance.iso"
INFO[2016-11-17T14:52:58Z]      "bootstrap.iso"
time=2016-11-17T14:53:00.512652209Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).uploadImages:115] [2.204239695s]
time=2016-11-17T14:53:00.512764927Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).RegisterExtension:156] com.vmware.vic.4203199f-23e0-e159-37c8-1bef8d75a10e
INFO[2016-11-17T14:53:00Z] Registering VCH as a vSphere extension
time=2016-11-17T14:53:04.659785193Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).RegisterExtension:156] [4.147011567s] com.vmware.vic.4203199f-23e0-e159-37c8-1bef8d75a10e
time=2016-11-17T14:53:04.659818820Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).startAppliance:96]
time=2016-11-17T14:53:07.126439566Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).ensureApplianceInitializes:857]
INFO[2016-11-17T14:53:07Z] Waiting for IP information
time=2016-11-17T14:53:07.126493906Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).waitForKey:646] guestinfo.vice..init.networks|client.assigned.IP
time=2016-11-17T14:53:20.172484407Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).waitForKey:646] [13.045982632s] guestinfo.vice..init.networks|client.assigned.IP
INFO[2016-11-17T14:53:20Z] Waiting for major appliance components to launch
DEBU[2016-11-17T14:53:20Z] waiting for vicadmin to start
time=2016-11-17T14:53:20.172777347Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).waitForKey:646] guestinfo.vice..init.sessions|vicadmin.started
time=2016-11-17T14:53:20.185235920Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).waitForKey:646] [12.458324ms] guestinfo.vice..init.sessions|vicadmin.started
DEBU[2016-11-17T14:53:20Z] waiting for docker personality to start
time=2016-11-17T14:53:20.185379651Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).waitForKey:646] guestinfo.vice..init.sessions|docker-personality.started
time=2016-11-17T14:53:20.196617042Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).waitForKey:646] [11.243187ms] guestinfo.vice..init.sessions|docker-personality.started
DEBU[2016-11-17T14:53:20Z] waiting for port layer to start
time=2016-11-17T14:53:20.196743745Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).waitForKey:646] guestinfo.vice..init.sessions|port-layer.started
time=2016-11-17T14:53:20.209869215Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).waitForKey:646] [13.115127ms] guestinfo.vice..init.sessions|port-layer.started
time=2016-11-17T14:53:20.209922592Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).applianceConfiguration:633]
time=2016-11-17T14:53:20.219844478Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).applianceConfiguration:633] [9.920912ms]
DEBU[2016-11-17T14:53:20Z] Obtained IP address for client interface: "10.101.33.50"
time=2016-11-17T14:53:20.219960391Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).ensureApplianceInitializes:857] [13.093520675s]
time=2016-11-17T14:53:20.220006497Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).startAppliance:96] [15.560185687s]
time=2016-11-17T14:53:20.220031540Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).CreateVCH:37] [33.402114885s] rm101vch4050
time=2016-11-17T14:53:20.220054462Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).CheckDockerAPI:678]
DEBU[2016-11-17T14:53:20Z] connection refused
DEBU[2016-11-17T14:53:21Z] Components not yet initialized, retrying
DEBU[2016-11-17T14:53:21Z] connection refused

Then lots of these last two lines for nearly ten minutes then this lot;

DEBU[2016-11-17T15:02:41Z] Components not yet initialized, retrying
DEBU[2016-11-17T15:02:41Z] connection refused
time=2016-11-17T15:02:41.897587672Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).CheckDockerAPI:678] [9m21.677503474s]
time=2016-11-17T15:02:41.897659013Z level=debug msg=[BEGIN] [github.com/vmware/vic/lib/install/management.(*Dispatcher).CollectDiagnosticLogs:165]
INFO[2016-11-17T15:02:41Z] Collecting 4f14e124-d8f9-4f57-a354-0197f9c9f3b6 vpxd.log
ERRO[2016-11-17T15:02:41Z] Failed to collect 4f14e124-d8f9-4f57-a354-0197f9c9f3b6 vpxd.log: context deadline exceeded
WARN[2016-11-17T15:02:41Z] No log data for 4f14e124-d8f9-4f57-a354-0197f9c9f3b6 vpxd.log
time=2016-11-17T15:02:41.897895174Z level=debug msg=[ END ] [github.com/vmware/vic/lib/install/management.(*Dispatcher).CollectDiagnosticLogs:165] [241.858µs]
ERRO[2016-11-17T15:02:41Z] --------------------
ERRO[2016-11-17T15:02:41Z] vic-machine-linux failed: Create timed out: use --timeout to add more time

Maybe you might spot something in this?

emlin commented 7 years ago

This error is because the vic services initialization failed, most likely it's portlayer service failed. Can you reach the ip 10.101.33.50? If yes, you can check logs from https://10.101.33.50:2378. If you have the installation success, it will show this address.

btw, we ever saw one deployment issue for the bridge network range configuration. I saw your parameter is --bridge-network-range '192.168.100.0/24', the range is too small for bridge network. You will need to make it at least /16 or bigger. If you find error message in portlayer service, which said bridge network configuration issue, this might be the reason.

Chopper3 commented 7 years ago

Thanks for coming back to me, I redeployed this VCH using /16 on the bridge-network, I can ping it but can't get anything from 2378 sorry.

emlin commented 7 years ago

if that's the case, run vic-machine debug --enable-ssh, to enable ssh connection. Then you're able to ssh to the vm. The log files are in /var/log/vic

hmahmood commented 7 years ago

@Chopper3 you need something bigger than /16. Each of the bridge networks that VIC allows for are /16, so you need something larger than that to accommodate more than one bridge network. The --bridge-network-range specifies the full pool for the bridge networks. So for instance it is 172.16.0.0/12 by default, which, if I am not mistaken, will allow for 16 /16 bridge networks.

Chopper3 commented 7 years ago

Sorry to be dim, looked around and can't see a working way to use that --enable-ssh, tried the '--enable-ssh=password, didn't work, used a space, used parentheses - it's not listed in the -x list - oh and I'll try with a /12 too

Chopper3 commented 7 years ago

actually both --enable-ssh and --rootpw both say 'flag provided but not defined' - have they been removed?

hmahmood commented 7 years ago

@Chopper3 have you tried not using those options for vic-machine debug? Just use the minimum options required, and vic-machine debug should turn on ssh with the default password.

Chopper3 commented 7 years ago

just redeployed just using --debug 1 - still not ssh, and root/password doesn't work at the VM console

hmahmood commented 7 years ago

Sorry I meant use the vic-machine-linux debug command with the bare minimum options.

Chopper3 commented 7 years ago

Which options would you suggest I drop - it's not far off being at the bare minimum anyway is it?

hmahmood commented 7 years ago

I believe in your case just ./vic-machine-linux debug --target 'rm101vcenter.room101.com' --user vicadmin@vsphere.local --password notactualpassword --compute-resource '/Room101/host/Main-Cluster/Resources/vSphere Integrated Containers/VCHs' --thumbprint D1:D5:00:99:80:28:51:7D:BB:A2:03:8D:7A:5E:7D:83:1E:B9:45:51 --name 'rm101vch4050' should suffice.

Chopper3 commented 7 years ago

Nope that won't find my port-groups - if you have multiple clusters in a vCentre you have to spell them out via path - I've spent the last week getting that bit working - I could drop the insecure-repo but everything else is needed - as I say this isn't a home lab anymore, it's a realistic vCenter.

hmahmood commented 7 years ago

The vic-machine-linux debug should not care about the port groups that you specified with create. The only options are:


NAME:
   vic-machine-linux debug - Debug VCH

USAGE:
   vic-machine-linux debug [command options] [arguments...]

OPTIONS:
   --target value, -t value             REQUIRED. ESXi or vCenter connection URL, specifying a datacenter if multiple exist e.g. root:password@VC-FQDN/datacenter (default: <nil>)
   --user value, -u value               ESX or vCenter user
   --password value, -p value           ESX or vCenter password (default: <nil>)
   --thumbprint value                   ESX or vCenter host certificate thumbprint
   --id value                           The ID of the Virtual Container Host, e.g. vm-220
   --name value, -n value               The name of the Virtual Container Host (default: "virtual-container-host")
   --compute-resource value, -r value   Compute resource path, e.g. myCluster/Resources/myRP. Default to <default cluster>/Resources
   --enable-ssh, --ssh                  Enable SSH server within appliance VM
   --authorized-key value, --key value  File with public key to place as /root/.ssh/authorized_keys
   --rootpw value, --pw value           Password to set for root user (non-persistent over reboots)
   --timeout value                      Time to wait for operation to complete (default: 3m0s)```
Chopper3 commented 7 years ago

Ok, was being dim, didn't realise you ran it against an existing VCH, so did this;

root@rm101vicc [ ~/vic ]# ./vic-machine-linux debug --target 'rm101vcenter.room101.com' --user vicadmin@vsphere.local --password not-actual-password --compute-resource '/Room101/host/Main-Cluster/Resources/vSphere Integrated Containers/VCHs' --thumbprint D1:D5:00:99:80:28:51:7D:BB:A2:03:8D:7A:5E:7D:83:1E:B9:45:51 --name 'rm101vch4050' --enable-ssh --password not-actual-password INFO[2016-11-21T18:45:53Z] ### Configuring VCH for debug #### INFO[2016-11-21T18:45:53Z] INFO[2016-11-21T18:45:53Z] VCH ID: VirtualMachine:vm-1827 INFO[2016-11-21T18:46:04Z] INFO[2016-11-21T18:46:04Z] Installer version: v0.7.0-6507-6c4627d INFO[2016-11-21T18:46:04Z] VCH version: v0.7.0-6507-6c4627d WARN[2016-11-21T18:46:04Z] Unable to identify address acceptable to host certificate INFO[2016-11-21T18:46:04Z] INFO[2016-11-21T18:46:04Z] SSH to appliance: INFO[2016-11-21T18:46:04Z] ssh root@10.101.33.50 INFO[2016-11-21T18:46:04Z] INFO[2016-11-21T18:46:04Z] vic-admin portal: INFO[2016-11-21T18:46:04Z] https://10.101.33.50:2378 INFO[2016-11-21T18:46:04Z] INFO[2016-11-21T18:46:04Z] Published ports can be reached at: INFO[2016-11-21T18:46:04Z] 10.101.33.50 INFO[2016-11-21T18:46:04Z] INFO[2016-11-21T18:46:04Z] Docker environment variables: INFO[2016-11-21T18:46:04Z] DOCKER_HOST=10.101.33.50:2376 INFO[2016-11-21T18:46:04Z] INFO[2016-11-21T18:46:04Z] Connect to docker: INFO[2016-11-21T18:46:04Z] docker -H 10.101.33.50:2376 --tls info INFO[2016-11-21T18:46:04Z] Completed successfully

Which is great, except the 'create' still fails with the same message, though I can now ssh in (my own password wasn't honoured though but I could login with the default one, so logs are below.

vic logs.txt

Oh and I can't get anything out of port 2378 still, also if I run just 'docker -H 10.101.33.50:2376 --tls info' on the photon VM I'm running 'vic-machine-linux create/debug' on I get 'Cannot connect to the Docker daemon. Is the docker daemon running on this host?', so I don't know how this debug command managed it.

emlin commented 7 years ago

the last line of the log file: time="2016-11-21T18:56:20Z" level=fatal msg="could not initialize port layer: bridge mask is not compatible with bridge pool mask"

emlin commented 7 years ago

is this the result with /12?

Chopper3 commented 7 years ago

damn no, will try again sorry

Chopper3 commented 7 years ago

Damn it - that's it - you can't have a small subnet! a /12 did it - thank you all very much indeed - it might be worth adding that this network MUST be a /12 into the documentation - cheers.

emlin commented 7 years ago

thanks for verify it. #3227 is to track the document issue

emlin commented 7 years ago

3212 is the issue opened few days ago to track this issue. So close this one as duplicate