Hello,
I'm experiencing a very strange issue, when I try to deploy the first VM, and the CopyCommand is executed I get : Connection timed out on SSVM side, but only after this task is executed, If I restart the secondary storage and ping,telnet,ssh on esxi everything works fine. SSVM : 2019-09-09 16:56:00,563 INFO [storage.resource.NfsSecondaryStorageResource] (agentRequest-Handler-5:null) Determined host sg-nfs.droxxx.com corresponds to IP 10.100.21.5 2019-09-09 16:56:17,087 INFO [storage.resource.PremiumSecondaryStorageResource] (agentRequest-Handler-2:job-258/job-259, cmd: CopyCommand) Add dynamic route/firewall entry for 10.100.21.4 2019-09-09 16:56:17,094 INFO [storage.resource.VmwareSecondaryStorageResourceHandler] (agentRequest-Handler-2:job-258/job-259, cmd: CopyCommand) Open new VmwareContext. vCenter: 10.100.21.4, user: administrator@vsphere.local, password: W**************** 2019-09-09 16:56:31,187 INFO [vmware.util.VmwareContext] (agentRequest-Handler-2:job-258/job-259, cmd: CopyCommand) New VmwareContext object, current outstanding count: 1 2019-09-09 16:56:31,341 INFO [storage.resource.PremiumSecondaryStorageResource] (agentRequest-Handler-2:job-258/job-259, cmd: CopyCommand) Add dynamic route/firewall entry for 180.xx.xx.18 2019-09-09 16:56:31,365 INFO [storage.resource.VmwareSecondaryStorageResourceHandler] (agentRequest-Handler-2:job-258/job-259, cmd: CopyCommand) Setup firewall rule for host: 180.xx.xx.18 2019-09-09 16:56:31,421 INFO [storage.resource.VmwareStorageProcessor] (agentRequest-Handler-2:job-258/job-259, cmd: CopyCommand) Template centos53-x64 is not setup yet. Set up template from secondary storage with uuid name: 5933a69e4b5830549e43a3fb4e8411b0 2019-09-09 16:56:31,515 INFO [storage.resource.VmwareStorageProcessor] (agentRequest-Handler-2:job-258/job-259, cmd: CopyCommand) Executing copyTemplateFromSecondaryToPrimary. secondaryStorage: nfs://sg-nfs.droxxx.com/home/secondary, templatePathAtS econdaryStorage: template/tmpl/1/7/, templateName: centos53-x64 2019-09-09 16:56:31,520 INFO [storage.resource.NfsSecondaryStorageResource] (agentRequest-Handler-2:job-258/job-259, cmd: CopyCommand) Determined host sg-nfs.droxxx.com corresponds to IP 10.100.21.5 2019-09-09 16:56:31,530 INFO [storage.resource.VmwareStorageProcessor] (agentRequest-Handler-2:job-258/job-259, cmd: CopyCommand) Secondary storage mount point: /mnt/SecStorage/ffdb8ec1-4895-3818-a5f0-3c84789ad7b0 2019-09-09 16:56:32,114 INFO [vmware.mo.HypervisorHostHelper] (agentRequest-Handler-2:job-258/job-259, cmd: CopyCommand) Resolving host name in url through vCenter, url: https://sg-001.droxxx.com/nfc/5245bb21-ce55-9cb1-8740-a19e701b3b10/disk-0.vm dk 2019-09-09 16:56:32,205 INFO [vmware.mo.HypervisorHostHelper] (agentRequest-Handler-2:job-258/job-259, cmd: CopyCommand) url https://sg-001.droxxx.com/nfc/5245bb21-ce55-9cb1-8740-a19e701b3b10/disk-0.vm dk is resolved to https://180.xxx.xxx.18/nfc/5245bb21-ce55-9cb1-8740-a19e701b3b10/disk-0.vmdk through vCenter Unable to connect, conn: sun.net.www.protocol.https.DelegateHttpsURLConnection:https://180.xxx.xxx.18 /nfc/52537de2-66ad-12be-0f63-4c9801826888/disk-0.vmdk, message: java.net.ConnectException: Connection timed out (Connection timed out), retry: 0 This is the output from ESXI before timeout : 9-09-09T16:15:04.442Z info vpxa[23807B70] [Originator@6876 sub=vpxLro opID=18121e6d-cb-94-cd-a7] [VpxLRO] -- BEGIN task-internal-233 -- vpxa -- vpxapi.VpxaService.reserveName -- 520fb9da-35e1-f9c2-60c8-8425c147253b 2019-09-09T16:15:04.442Z verbose vpxa[23807B70] [Originator@6876 sub=vpxaDatastoreContext opID=18121e6d-cb-94-cd-a7] [VpxaDatastoreContext] Resolved URL ds:///vmfs/volumes/5d64da34-40bfc2f2-8ff0-a0369f1f6fd8/ to localPath /vmfs/volumes/5d64da34-40bfc2f2-8ff0-a0369f1f6fd8/ 2019-09-09T16:15:04.443Z verbose vpxa[23807B70] [Originator@6876 sub=vpxaNameReserve opID=18121e6d-cb-94-cd-a7] [VpxaNameReserve::ReserveFileWithGivenRootDir] Directory /vmfs/volumes/5d64da34-40bfc2f2-8ff0-a0369f1f6fd8 is available for use 2019-09-09T16:15:04.443Z verbose vpxa[23807B70] [Originator@6876 sub=vpxaDatastoreContext opID=18121e6d-cb-94-cd-a7] [VpxaDatastoreContext] Resolved URL /vmfs/volumes/5d64da34-40bfc2f2-8ff0-a0369f1f6fd8/5933a69e4b5830549e43a3fb4e 8411b0 to localPath /vmfs/volumes/5d64da34-40bfc2f2-8ff0-a0369f1f6fd8/5933a69e4b5830549e43a3fb4e 8411b0 2019-09-09T16:15:04.443Z verbose vpxa[23807B70] [Originator@6876 sub=vpxaDatastoreContext opID=18121e6d-cb-94-cd-a7] [Url] Resolved localPath /vmfs/volumes/5d64da34-40bfc2f2-8ff0-a0369f1f6fd8/ to URL ds:///vmfs/volumes/5d64da34-40bfc2f2-8ff0-a0369f1f6fd8/ 2019-09-09T16:15:04.445Z verbose vpxa[23807B70] [Originator@6876 sub=vpxaNameReserve opID=18121e6d-cb-94-cd-a7] [VpxaNameReserve] Reserved directory only, name /vmfs/volumes/5d64da34-40bfc2f2-8ff0-a0369f1f6fd8/5933a69e4b5830549e43a3fb4e 8411b0, stable name /vmfs/volumes/5d64da34-40bfc2f2-8ff0-a0369f1f6fd8/5933a69e4b5830549e43a3fb4e 8411b0 2019-09-09T16:15:04.445Z verbose vpxa[23807B70] [Originator@6876 sub=vpxaDatastoreContext opID=18121e6d-cb-94-cd-a7] [Url] Resolved localPath /vmfs/volumes/5d64da34-40bfc2f2-8ff0-a0369f1f6fd8/5933a69e4b5830549e43a3fb4e 8411b0 to URL ds:///vmfs/volumes/5d64da34-40bfc2f2-8ff0-a0369f1f6fd8/5933a69e4b5830549e43a 3fb4e8411b0 2019-09-09T16:15:04.445Z verbose vpxa[23807B70] [Originator@6876 sub=journal opID=18121e6d-cb-94-cd-a7] Deleting Journal /var/log/vmware/journal/1568045704.4. 2019-09-09T16:15:04.446Z verbose vpxa[23807B70] [Originator@6876 sub=vpxaVmomi opID=18121e6d-cb-94-cd-a7] [VpxaVmomi] SetStatusDone was called with syncGenNo (395) 2019-09-09T16:15:04.446Z info vpxa[23807B70] [Originator@6876 sub=vpxLro opID=18121e6d-cb-94-cd-a7] [VpxLRO] -- FINISH task-internal-233 2019-09-09T16:15:04.472Z verbose vpxa[FFE9CB70] [Originator@6876 sub=SoapAdapter] Responded to service state request 2019-09-09T16:15:04.482Z verbose vpxa[FFE18B70] [Originator@6876 sub=PropertyProvider opID=18121e6d-cb-94-cd-ef] RecordOp ASSIGN: info.reason, task-234. Applied change to temp map. 2019-09-09T16:15:04.482Z verbose vpxa[FFE18B70] [Originator@6876 sub=PropertyProvider opID=18121e6d-cb-94-cd-ef] [CommitChangesAndNotify] Updating cached values 2019-09-09T16:15:04.482Z verbose vpxa[FFE18B70] [Originator@6876 sub=PropertyProvider opID=18121e6d-cb-94-cd-ef] RecordOp ADD: recentTask["task-234"], vpxaTaskManager. Sent notification immediately. 2019-09-09T16:15:04.482Z verbose vpxa[FFE5AB70] [Originator@6876 sub=PropertyProvider] RecordOp ASSIGN: info.startTime, task-234. Applied change to temp map. 2019-09-09T16:15:04.482Z verbose vpxa[FFE5AB70] [Originator@6876 sub=PropertyProvider] [CommitChangesAndNotify] Updating cached values 2019-09-09T16:15:04.482Z verbose vpxa[FFE5AB70] [Originator@6876 sub=PropertyProvider opID=18121e6d-cb-94-cd-ef] RecordOp ASSIGN: info.state, task-234. Applied change to temp map. Also I'm not sure from where he get this IP: 180.xx.xx.18 this is the public IP but the domain name only resolves on internal ip : 10.100.21.201, I'm also able to ping on this one. but not on the public IP : 180.xx.xx.18 . Can I get some help on this? Thank you in advance. Cristian
