Transport (VMDB) error -45: Failed to connect to peer process

[mobla]

VIC: vic-machine-windows.exe version v0.7.0-7145-3fab0b0 (0.8.0 rc1) Harbor: 0.5.0 vCenter 6.5 - 2016 RTM3 - ob-4602587 Client Machine - Windows 7 (virtual box driver) and Linux (Photon) - just to push an image from standard docker to harbor (for no-tls)

Steps:

1. Deploy Harbor OVA (http) and configure it with LDAP
2. Push busy box image to harbor
3. Create VCH no-tls with insecure-registry :80
4. Run the busybox image - got this error during poweron the container (vm)

VCH admin portal is pulling only 500 lines of vpxd log @mdubya66 said there is an issue open for this already.

vpxd log snippet

2016-11-22T21:17:11.671Z info vpxd[7FCEA67CF700] [Originator@6876 sub=vpxLro opID=11350fbe] [VpxLRO] -- FINISH task-506
2016-11-22T21:17:11.671Z info vpxd[7FCEA67CF700] [Originator@6876 sub=Default opID=11350fbe] [VpxLRO] -- ERROR task-506 -- vm-76 -- vim.VirtualMachine.powerOn: vim.fault.GenericVmConfigFault:
--> Result:
--> (vim.fault.GenericVmConfigFault) {
-->    faultCause = (vmodl.MethodFault) null,
-->    faultMessage = (vmodl.LocalizableMessage) [
-->       (vmodl.LocalizableMessage) {
-->          key = "msg.vigor.transport.vmdb",
-->          arg = (vmodl.KeyAnyValue) [
-->             (vmodl.KeyAnyValue) {
-->                key = "1",
-->                value = "-45"
-->             },
-->             (vmodl.KeyAnyValue) {
-->                key = "2",
-->                value = "Failed to connect to peer process"
-->             }
-->          ],
-->          message = "Transport (VMDB) error -45: Failed to connect to peer process."
-->       },
-->       (vmodl.LocalizableMessage) {
-->          key = "vpxd.vm.poweron.unexpectedfailure",
-->          arg = (vmodl.KeyAnyValue) [
-->             (vmodl.KeyAnyValue) {
-->                key = "1",
-->                value = "wcBusybox1-21f6414ab91eea2f0c18e7a4fd065806b1d95e6e4dff003e1e4d86206337922e"
-->             }
-->          ],
-->          message = "An unexpected error was received from the ESX host while powering on VM wcBusybox1-21f6414ab91eea2f0c18e7a4fd065806b1d95e6e4dff003e1e4d86206337922e."
-->       }
-->    ],
-->    reason = "Transport (VMDB) error -45: Failed to connect to peer process."
-->    msg = "Transport (VMDB) error -45: Failed to connect to peer process."
--> }

Hostd log snippet

2016-11-22T21:17:11.989Z info hostd[E981B70] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/5834a33f-379a2af0-dbb1-020006c9cf7b/wcBusybox1-21f6414ab91eea2f0c18e7a4fd065806b1d95e6e4dff003e1e4d86206337922e/wcBusybox1-
2016-11-22T21:17:11.989Z verbose hostd[E981B70] [Originator@6876 sub=PropertyProvider opID=11350fbe-01-02-4a-bf1a user=vpxuser:vpxuser] RecordOp ASSIGN: disabledMethod, 4. Sent notification immediately.
2016-11-22T21:17:11.989Z info hostd[E981B70] [Originator@6876 sub=Vimsvc.TaskManager opID=11350fbe-01-02-4a-bf1a user=vpxuser:vpxuser] Task Completed : haTask-pool2-vim.ResourcePool.moveInto-127033076 Status succ
2016-11-22T21:17:11.989Z verbose hostd[E981B70] [Originator@6876 sub=PropertyProvider opID=11350fbe-01-02-4a-bf1a user=vpxuser:vpxuser] RecordOp ASSIGN: info, haTask-pool2-vim.ResourcePool.moveInto-127033076. App
2016-11-22T21:17:12.028Z info hostd[97C2B70] [Originator@6876 sub=Vimsvc.TaskManager opID=11350fbe-01-99-bf20 user=vpxuser:VSPHERE.LOCAL\Administrator] Task Created : haTask-4-vim.VirtualMachine.powerOn-127033077
2016-11-22T21:17:12.028Z verbose hostd[97C2B70] [Originator@6876 sub=PropertyProvider opID=11350fbe-01-99-bf20 user=vpxuser:VSPHERE.LOCAL\Administrator] RecordOp ADD: recentTask["haTask-4-vim.VirtualMachine.power
2016-11-22T21:17:12.028Z verbose hostd[97C2B70] [Originator@6876 sub=PropertyProvider opID=11350fbe-01-99-bf20 user=vpxuser:VSPHERE.LOCAL\Administrator] RecordOp ADD: recentTask["haTask-4-vim.VirtualMachine.power
2016-11-22T21:17:12.028Z verbose hostd[97C2B70] [Originator@6876 sub=PropertyProvider opID=11350fbe-01-99-bf20 user=vpxuser:VSPHERE.LOCAL\Administrator] RecordOp ASSIGN: info, haTask-4-vim.VirtualMachine.powerOn-
2016-11-22T21:17:12.031Z verbose hostd[97C2B70] [Originator@6876 sub=PropertyProvider opID=11350fbe-01-99-bf20 user=vpxuser:VSPHERE.LOCAL\Administrator] RecordOp REMOVE: latestPage[220], session[52a946ef-7a94-00f
2016-11-22T21:17:12.031Z verbose hostd[97C2B70] [Originator@6876 sub=PropertyProvider opID=11350fbe-01-99-bf20 user=vpxuser:VSPHERE.LOCAL\Administrator] RecordOp ADD: latestPage[230], session[52a946ef-7a94-00fa-7
2016-11-22T21:17:12.031Z verbose hostd[97C2B70] [Originator@6876 sub=PropertyProvider opID=11350fbe-01-99-bf20 user=vpxuser:VSPHERE.LOCAL\Administrator] RecordOp ASSIGN: latestEvent, ha-eventmgr. Applied change t
2016-11-22T21:17:12.031Z info hostd[97C2B70] [Originator@6876 sub=Vimsvc.ha-eventmgr opID=11350fbe-01-99-bf20 user=vpxuser:VSPHERE.LOCAL\Administrator] Event 230 : wcBusybox1-21f6414ab91eea2f0c18e7a4fd065806b1d95
2016-11-22T21:17:12.031Z info hostd[97C2B70] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/5834a33f-379a2af0-dbb1-020006c9cf7b/wcBusybox1-21f6414ab91eea2f0c18e7a4fd065806b1d95e6e4dff003e1e4d86206337922e/wcBusybox1-
2016-11-22T21:17:12.031Z info hostd[97C2B70] [Originator@6876 sub=Libs opID=11350fbe-01-99-bf20 user=vpxuser:VSPHERE.LOCAL\Administrator] SIOC: SIOC is notified not to start injector
2016-11-22T21:17:12.032Z verbose hostd[97C2B70] [Originator@6876 sub=PropertyProvider opID=11350fbe-01-99-bf20 user=vpxuser:VSPHERE.LOCAL\Administrator] RecordOp ASSIGN: disabledMethod, 4. Sent notification immed
2016-11-22T21:17:12.032Z verbose hostd[97C2B70] [Originator@6876 sub=PropertyProvider opID=11350fbe-01-99-bf20 user=vpxuser:VSPHERE.LOCAL\Administrator] RecordOp ASSIGN: info.cancelable, haTask-4-vim.VirtualMachi
2016-11-22T21:17:12.032Z verbose hostd[97C2B70] [Originator@6876 sub=PropertyProvider opID=11350fbe-01-99-bf20 user=vpxuser:VSPHERE.LOCAL\Administrator] RecordOp ASSIGN: info.cancelable, haTask-4-vim.VirtualMachi
2016-11-22T21:17:12.034Z info hostd[97C2B70] [Originator@6876 sub=Libs opID=11350fbe-01-99-bf20 user=vpxuser:VSPHERE.LOCAL\Administrator] DictionaryLoad: Cannot open file "/usr/lib/vmware/config": No such file or
2016-11-22T21:17:12.034Z info hostd[97C2B70] [Originator@6876 sub=Libs opID=11350fbe-01-99-bf20 user=vpxuser:VSPHERE.LOCAL\Administrator] Could not expand environment variable HOME.
2016-11-22T21:17:12.034Z info hostd[97C2B70] [Originator@6876 sub=Libs opID=11350fbe-01-99-bf20 user=vpxuser:VSPHERE.LOCAL\Administrator] DictionaryLoad: Cannot open file "~/.vmware/config": No such file or direc
2016-11-22T21:17:12.036Z verbose hostd[9781B70] [Originator@6876 sub=PropertyProvider opID=3159bf22 user=vpxuser] RecordOp ASSIGN: info, haTask--vim.event.EventHistoryCollector.readNext-127033078. Applied change
2016-11-22T21:17:12.036Z verbose hostd[9781B70] [Originator@6876 sub=PropertyProvider opID=3159bf22 user=vpxuser] RecordOp ASSIGN: info, haTask--vim.event.EventHistoryCollector.readNext-127033078. Applied change
2016-11-22T21:17:12.038Z verbose hostd[9781B70] [Originator@6876 sub=PropertyProvider opID=3159bf23 user=vpxuser] RecordOp ASSIGN: info, haTask--vim.event.EventHistoryCollector.readNext-127033079. Applied change
2016-11-22T21:17:12.038Z verbose hostd[9781B70] [Originator@6876 sub=PropertyProvider opID=3159bf23 user=vpxuser] RecordOp ASSIGN: info, haTask--vim.event.EventHistoryCollector.readNext-127033079. Applied change
2016-11-22T21:17:12.047Z info hostd[97C2B70] [Originator@6876 sub=Libs opID=11350fbe-01-99-bf20 user=vpxuser:VSPHERE.LOCAL\Administrator] Starting vmx as /bin/vmx
2016-11-22T21:17:12.047Z info hostd[97C2B70] [Originator@6876 sub=Libs opID=11350fbe-01-99-bf20 user=vpxuser:VSPHERE.LOCAL\Administrator] Starting vmx as /bin/vmx
2016-11-22T21:17:12.047Z info hostd[97C2B70] [Originator@6876 sub=vm:VigorExecVMXExCommon: VM /vmfs/volumes/5834a33f-379a2af0-dbb1-020006c9cf7b/wcBusybox1-21f6414ab91eea2f0c18e7a4fd065806b1d95e6e4dff003e1e4d86206
2016-11-22T21:17:12.047Z info hostd[97C2B70] [Originator@6876 sub=vm:VigorExecVMXExCommon: Exec()'ing /bin/vmx /vmfs/volumes/5834a33f-379a2af0-dbb1-020006c9cf7b/wcBusybox1-21f6414ab91eea2f0c18e7a4fd065806b1d95e6e
2016-11-22T21:17:12.048Z info hostd[97C2B70] [Originator@6876 sub=Libs opID=11350fbe-01-99-bf20 user=vpxuser:VSPHERE.LOCAL\Administrator] Vigor: VMKernel_ForkExec(/bin/vmx, detached=1): status=0 pid=69749
- /var/log/hostd.log 13346/13478 99%

[mdubya66]

can you upload the full log bundle?

[mobla]

https://files.slack.com/files-tmb/T024JFTN4-F35UM3DHR-600055dcaa/capture_720.jpg

vlakshmivenkat@vlakshmivenkat MINGW64 ~/vic
$ docker -H 10.160.68.216:2375 run --name wcBusybox1 10.192.52.124:80/iteration2/busybox:1.0 /bin/sh
Unable to find image '10.192.52.124:80/iteration2/busybox:1.0' locally
Pulling from iteration2/busybox
56bec22e3559: Pull complete
a3ed95caeb02: Pull complete
Digest: sha256:0d68d5caaaae1b3014e78e2c292a9f0968b5b15258760457a86291c76f51a17f
Status: Downloaded newer image for iteration2/busybox:1.0
C:\Program Files\Docker Toolbox\docker.exe: Error response from daemon: Server error from portlayer: Transport (VMDB) error
peer process..

[mobla]

container-logs.tar.gz

[mobla]

vsphere.tar.gz

[andrewtchin]

i'm not sure if this is relevant, but saw this in vpxd.log

2016-11-22T21:17:07.534Z info vpxd[7FCEA76ED700] [Originator@6876 sub=pbm opID=2535c32] PBMCallback: DetermineDatastoreForDisk: No datastore for disk -1 in config,      filePath 'ds:///vmfs/volumes/5834a33f-379a2af0-dbb1-020006c9cf7b/VCH3/VIC/4235a97a-6b86-6bfb-280b-02fdc62512d6/images/                                                   9967c5ad88de8c101809f7f22d4774b6791fe46ac3033d57abf7ebb1dd8e36ee/9967c5ad88de8c101809f7f22d4774b6791fe46ac3033d57abf7ebb1dd8e36ee.vmdk'

[emlin]

@mobla So you're using vc 6.5. I'm also running test on this version. Do you have any feature enabled in your vc env? For example, DRS, vSAN, etc.

[mobla]

@emlin: Since VCH is deployed in vCenter, vic-machine create expects a. DRS to be enabled in the cluster (so yes) b. DVPG (DVS)

No vSAN, but viSCSI datastores (shared) added to the vESXi hosts..

Thanks, Murali

[mobla]

Looks like this is a datastore disk space issue. We are able to run it with enough disk space in datastore.

Another candidate for "Error message" improvement?

[TopSGW]

I faced the same issues