Standalone Converter failed at 98%

[scoutt]

I have tried many times but as long as you ckeck "Reconfigure Destination Virtual Machine" in the advacend settings under "Post-conversion Processing" it errors out at 98%. The logs say it timed out.

[2011-10-05 09:02:27.781 01600 error 'App'] [task,344] [LRO] Unexpected Exception: converter.fault.ReconfigurationFault
[2011-10-05 09:02:27.812 01600 info 'App'] [task,373] [task-4] -- ERROR -- Convert: converter.fault.ReconfigurationFault
(converter.fault.ReconfigurationFault) {
   dynamicType = <unset>,
   faultCause = (vmodl.MethodFault) null,
   description = "Operation timed out",
   msg = "",
}

It could be due to DEP but how do you turn it off in Win7? I am using 4.3 for the converter going to a 4.x ESX server. I hve done this before with version 4.1.1 of the converter but now it won't work. How would I convert a win7 box and have it work? If I uncheck that box it completes 100% but Winodws complaines it sees to many hardware changes and fails to boot.

[Ivan Ivanov]

Can you provide full logs? It could get clearer what operation had timed out and what the problem is. Also, can you try Conveter 5.0 instead of 4.3?

[scoutt]

Where are all the logs at and I will be sure to get them

[Ivan Ivanov]

When you right-click on the failed task there should be an "export logs" command. It should generate a log bundle with all logs.

[scoutt]

Thought thats where they were but just wanted to verify.

[Ivan Ivanov]

Here is what is in the agent log:

[#8] [2011-10-05 09:01:18.894 02372 error 'task-6'] [GetDiskTicketInfos] Timed out while waiting for the response.

[#8] [2011-10-05 09:01:18.894 02372 error 'task-6'] ReconfigTask failed to open the target. Error Operation timed out

[#8] [2011-10-05 09:01:18.894 02372 error 'task-6'] TaskImpl has failed with MethodFault::Exception: converter.fault.ReconfigurationFault

[#8] [2011-10-05 09:01:18.894 02372 error 'App'] Task failed:

[#8] [2011-10-05 09:01:18.894 02372 info 'task-6'] Scheduled timer canceled, StopKeepAlive succeeds

[#8] [2011-10-05 09:01:18.894 02372 info 'App'] Task Completed : task-6

[#8] [2011-10-05 09:02:18.907 04232 warning 'task-6'] [PassDiskTickets] There is no request corresonding to this response, ignoring...

Reconfiguration opens the target VMDK, mounts the system volume and updates some registry values in order to make the destination bootable. GetDiskTicketInfos tries to get NFC tickets from ESX or VC server  (that is, one-shot passwords) for establishing NFC session to the ESX host that would allow to access the target VMDK directly. The error is timeout while waiting for a NFC ticket.

In order to get NFC ticket from ESX/VC one needs to have an authenticated connection, that means login credentials. Since Converter Agent is deployed on an (unknown unsecure) source machine, in order to avoid passing ESX/VC credentials to agent, there is a mechanism that allows Agent to request an NFC ticket from the Worker (which is on the same machine where Converter Server has been installed), it in turn requests an NFC ticket and passes it back to the agent which then connects to the VMDK. Looking at the Worker log there is the following part:

[#2] [2011-10-05 09:00:23.343 01416 info 'task-1'] Reusing existing VIM connection to esxsrv17.jacksoncounty.org

[#2] [2011-10-05 09:02:23.359 01416 info 'task-1'] GetManagedDiskName: Get virtual disk filebacking [datastore1] E1Win72/E1Win72.vmdk

[#2] [2011-10-05 09:02:23.359 01416 info 'task-1'] GetManagedDiskName: ticket has empty hostname, using hostname esxsrv17.jacksoncounty.org from connection

[#2] [2011-10-05 09:02:23.359 01416 info 'task-1'] GetManagedDiskName: updating nfc port as 902

[#2] [2011-10-05 09:02:23.359 01416 info 'task-1'] GetManagedDiskName: get protocol as ha-nfc

[#2] [2011-10-05 09:02:23.359 01416 info 'task-1'] GetManagedDiskName: Get disklib file name as ha-nfc://[datastore1] E1Win72/[e-mail]:902!52 e5 d4 3c 56 91 58 77-02 cf 40 d9 46 2b 29 26

So the connection to the ESX host happened at 9:00:23, but then the actual NFC ticket was returned at 9:02:23, that is 2 minutes later. The timeout in agent has been set to 1 minute, so that's why it fails with a timeout error. However in the agent log the last message is about a response without a pending requeest - this is the response we got with 2 minutes delay and we have abandoned waiting for. During this time Converter has made just one call to the ESX server, which is looking for the target VM.

I have no idea why this search took so long - a network problem, heavy load on the ESX host, etc. However the code in Converter is pretty straight forward.

[scoutt]

Ok, so I tried 5.0 and it completed successfully. Even with the Reconfiguration checked. Not sure what happend with 4.3 and why it timed out. I can trying to convert a windows 7 box to a test server so it is not like it is being used heavily.

So it appears everything is ok.