Re: VM customizing takes long time.

cdickerson · ‎12-04-2008

I have deployed VM View twice. And in both environments, I am seeing great delays in the time it takes to customize the VM. Usually anywhere from 3-6 minutes. This seems like a long time. Looking at AD the computer is added rather quickly, and then it just seems to sit there and isn't usuable until it's status changes to Ready. Any ideas what is slowing this customizing process down, or is this normal? thanks

-Craig

admin · ‎12-05-2008

Are you using Linked Clone Pools or normal automatical pools with a template and a customization script.

If you are using Linked Clones, the first VM should take up to 10 minutes depending on the esx / storage performance and the linked clones will be deployed rapid in about 10-30 seconds.

If you are using a customizationand a template it's a normal time. It depends on the vDisk size, because the VM is a full clone out of the template and after that the broker is running the sysprep on the VM.

Thanks,

Christoph

knudt · ‎12-05-2008

I have seen this behaviour as well (using linked clones). The first does indeed take a long time (~10 minutes), but subsequent deploys take the 3-6 minutes originally posted.

~If you find this or any other post helpful, please award points. Also mark thread as answered if question was answered successfully.~ Brian Knudtson vExpert, VCP, VCAP

cdickerson · ‎12-05-2008

yeah I am using linked clones. I understand the first time the clone is put on the datastore it will take a while. I am referring to the additional vm's afterwards. My local VMWare SE was saying that they were seeing new pc's deployed in under a minute (actually 25 seconds in some cases I was told) so that is what my expectations were.

Rodos · ‎12-05-2008

Yes, the subsequent ones should be quick. There are a number of steps in the creation and you see multiple tasks in the VC, are any of them taking longer than others? I The most time consuming part is booting them. How many creations are you running in parallel?

Rodos

Considering awarding points if this is of use

Rodos {size:10px}{color:gray}Consider the use of the helpful or correct buttons to award points. Blog: http://rodos.haywood.org/{color}{size}

admin · ‎12-07-2008

Also the question is:

What storage are you using?

How busy is the storage, how your ESX boxes?

How many deployments are running concurrent?

Thanks,

Christoph

cdickerson · ‎12-07-2008

yeah I see the multiple steps in VC. they all complete within a few seconds. The new linked clone is powered on and I can go to AD and I can see that quickprep has added it to AD. But, it will say customizing for an additional ~5 minutes. I have tried this in three different environments and in all the customizing takes a while. One environment was using DAS and the other two were using iSCSI. Of those two iSCSI, one was an Equallogic setup and the other was my test lab using openfiler. The utilization of the storage and ESX servers was very low. Each time, only one deployment was running. thanks

-Craig

admin · ‎12-08-2008

Hi could you check the View Composer Logfile please or post the part, where the customization should happen?

You can find the log in: C:\Program Files\VMware\View .... Composer ... \Logs\...

Or/and:

C:\Documents and Settings\All Users\Local Settings\Application data\Vmware ....

Thanks,

Christoph

rjansen87 · ‎12-10-2008

I have a similar problem, here is the end of my vmware-viewcomposer.log.

2008-12-10 17:47:14,506 | UFA thread 3 | INFO | CommonLib.UfaSubsystem.UfaWorkItem - UFA: finish init disk operation for disk: datastore: ***vmfs03 View_XP_P_1/View_XP_P_1-vdm-user-disk-D.vmdk, host: ***, port: 902 successfully.

2008-12-10 17:47:15,490 | UFA thread 3 | INFO | ServiceCore.Action.UfaInitializeDiskAction - UfaInitializeDiskAction: finished init disk: ***vmfs03 View_XP_P_1/View_XP_P_1-vdm-user-disk-D.vmdk.

2008-12-10 17:47:15,506 | WFE thread 9 | INFO | ServiceCore.LockManager.LockManager - Multiple releases are reuiqred for SimClone with ids:

2008-12-10 17:47:15,506 | WFE thread 9 | INFO | ServiceCore.LockManager.LockManager - A release is requested for DeploymentGroup with id: f972eac7-c7ef-40a4-9eeb-8ac86264f45a

could you help me out?

cdickerson · ‎12-11-2008

Here is what I see in the vmware-viewcomposer.log.

2008-12-11 21:44:41,473 | 24 | INFO | Sim.ServiceCore.SimServiceApiVal - Call GetVersion.

2008-12-11 21:44:41,754 | 24 | INFO | Sim.ServiceCore.SimServiceApiImpl - CreateSviClones was called for deployment group a1c079b1-7f97-4b18-a350-7470a644ebb7, for 1 clones.

2008-12-11 21:44:41,754 | 24 | INFO | Sim.ServiceCore.SimServiceApiImpl - Received a request to create 1 clones for deployment group a1c079b1-7f97-4b18-a350-7470a644ebb7. Filed as request id 4bada5eb-925f-492f-aab7-1b755328b4f7

2008-12-11 21:44:41,754 | 24 | INFO | ServiceCore.LockManager.LockManager - A lock is requested for DeploymentGroup with id: a1c079b1-7f97-4b18-a350-7470a644ebb7

2008-12-11 21:44:42,128 | 24 | ERROR | NHibernate.Util.ADOExceptionReporter - ERROR [SQL Native Client][SQL Server]Violation of PRIMARY KEY constraint 'PK_SVI_VM_NAME'. Cannot insert duplicate key in object 'dbo.SVI_VM_NAME'.

ERROR [SQL Native Client][SQL Server]The statement has been terminated.

2008-12-11 21:44:42,128 | 24 | ERROR | NHibernate.Impl.SessionImpl - could not synchronize database state with session

NHibernate.ADOException: could not insert: http://VMware.Sim.ServiceCore.DataObject.VmNameDo#xppc5[SQL: INSERT INTO SVI_VM_NAME (NAME) VALUES (?)] ---> System.Data.Odbc.OdbcException: ERROR [SQL Native Client][SQL Server]Violation of PRIMARY KEY constraint 'PK_SVI_VM_NAME'. Cannot insert duplicate key in object 'dbo.SVI_VM_NAME'.

ERROR [SQL Native Client][SQL Server]The statement has been terminated.

at System.Data.Odbc.OdbcConnection.HandleError(OdbcHandle hrHandle, RetCode retcode)

at System.Data.Odbc.OdbcCommand.ExecuteReaderObject(CommandBehavior behavior, String method, Boolean needReader, Object[] methodArguments, SQL_API odbcApiMethod)

at System.Data.Odbc.OdbcCommand.ExecuteReaderObject(CommandBehavior behavior, String method, Boolean needReader)

at System.Data.Odbc.OdbcCommand.ExecuteNonQuery()

at NHibernate.Impl.NonBatchingBatcher.AddToBatch(IExpectation expectation)

at NHibernate.Persister.Entity.AbstractEntityPersister.Insert(Object id, Object[] fields, Boolean[] notNull, Int32 j, SqlCommandInfo sql, Object obj, ISessionImplementor session)

End of inner exception stack trace ---

at NHibernate.Persister.Entity.AbstractEntityPersister.Insert(Object id, Object[] fields, Boolean[] notNull, Int32 j, SqlCommandInfo sql, Object obj, ISessionImplementor session)

at NHibernate.Persister.Entity.AbstractEntityPersister.Insert(Object id, Object[] fields, Object obj, ISessionImplementor session)

at NHibernate.Impl.ScheduledInsertion.Execute()

at NHibernate.Impl.SessionImpl.Execute(IExecutable executable)

at NHibernate.Impl.SessionImpl.ExecuteAll(IList list)

at NHibernate.Impl.SessionImpl.Execute()

2008-12-11 21:44:42,128 | 24 | FATAL | ServiceCore.Persistence.TranCollector -

TranId:c3cf1ba7-60d8-47db-93eb-1939f14f8a6e, queries:Transaction before commit

Stack Trace:

GetStackTrace

Add

Commit

SaveObjectArray

SaveVmName

SetUniqueNames

.ctor

CreateSviClones

SyncInvokeCreateSviClones

Invoke

InvokeBegin

ProcessMessage5

ProcessMessage4

ProcessMessage3

ProcessMessage2

ProcessMessage1

Process

DispatchAndReleasePump

HandleRequest

AsyncMessagePump

OnAsyncReceiveComplete

UnhandledExceptionFrame

Complete

Set

EnqueueAndDispatch

Enqueue

HttpContextReceived

OnGetContextCore

OnGetContext

UnhandledExceptionFrame

Complete

ProtectedInvokeCallback

WaitCallback

PerformIOCompletionCallback

Stack Trace:

GetStackTrace

Log

Commit

SaveObjectArray

SaveVmName

SetUniqueNames

.ctor

CreateSviClones

SyncInvokeCreateSviClones

Invoke

InvokeBegin

ProcessMessage5

ProcessMessage4

ProcessMessage3

ProcessMessage2

ProcessMessage1

Process

DispatchAndReleasePump

HandleRequest

AsyncMessagePump

OnAsyncReceiveComplete

UnhandledExceptionFrame

Complete

Set

EnqueueAndDispatch

Enqueue

HttpContextReceived

OnGetContextCore

OnGetContext

UnhandledExceptionFrame

Complete

ProtectedInvokeCallback

WaitCallback

PerformIOCompletionCallback

2008-12-11 21:44:42,128 | 24 | FATAL | ServiceCore.Persistence.SimDaoHelper - Log and throw: Hibernate threw exception during Commit.

NHibernate.ADOException: could not insert: http://VMware.Sim.ServiceCore.DataObject.VmNameDo#xppc5[SQL: INSERT INTO SVI_VM_NAME (NAME) VALUES (?)] ---> System.Data.Odbc.OdbcException: ERROR [SQL Native Client][SQL Server]Violation of PRIMARY KEY constraint 'PK_SVI_VM_NAME'. Cannot insert duplicate key in object 'dbo.SVI_VM_NAME'.

ERROR [SQL Native Client][SQL Server]The statement has been terminated.

at System.Data.Odbc.OdbcConnection.HandleError(OdbcHandle hrHandle, RetCode retcode)

at System.Data.Odbc.OdbcCommand.ExecuteReaderObject(CommandBehavior behavior, String method, Boolean needReader, Object[] methodArguments, SQL_API odbcApiMethod)

at System.Data.Odbc.OdbcCommand.ExecuteReaderObject(CommandBehavior behavior, String method, Boolean needReader)

at System.Data.Odbc.OdbcCommand.ExecuteNonQuery()

at NHibernate.Impl.NonBatchingBatcher.AddToBatch(IExpectation expectation)

at NHibernate.Persister.Entity.AbstractEntityPersister.Insert(Object id, Object[] fields, Boolean[] notNull, Int32 j, SqlCommandInfo sql, Object obj, ISessionImplementor session)

End of inner exception stack trace ---

at NHibernate.Persister.Entity.AbstractEntityPersister.Insert(Object id, Object[] fields, Boolean[] notNull, Int32 j, SqlCommandInfo sql, Object obj, ISessionImplementor session)

at NHibernate.Persister.Entity.AbstractEntityPersister.Insert(Object id, Object[] fields, Object obj, ISessionImplementor session)

at NHibernate.Impl.ScheduledInsertion.Execute()

at NHibernate.Impl.SessionImpl.Execute(IExecutable executable)

at NHibernate.Impl.SessionImpl.ExecuteAll(IList list)

at NHibernate.Impl.SessionImpl.Execute()

at NHibernate.Impl.SessionImpl.Flush()

at NHibernate.Transaction.AdoTransaction.Commit()

at VMware.Sim.ServiceCore.Persistence.Database.SimDbTransaction.Commit()

2008-12-11 21:44:42,128 | 24 | FATAL | ServiceCore.Persistence.SimDaoHelper - A DAO exception is thrown:

VMware.Sim.ServiceCore.Exception.SimDaoException: [SQL Native Client][SQL Server]Violation of PRIMARY KEY constraint 'PK_SVI_VM_NAME'. Cannot insert duplicate key in object 'dbo.SVI_VM_NAME'. ---> NHibernate.ADOException: could not insert: http://VMware.Sim.ServiceCore.DataObject.VmNameDo#xppc5[SQL: INSERT INTO SVI_VM_NAME (NAME) VALUES (?)] ---> System.Data.Odbc.OdbcException: ERROR [SQL Native Client][SQL Server]Violation of PRIMARY KEY constraint 'PK_SVI_VM_NAME'. Cannot insert duplicate key in object 'dbo.SVI_VM_NAME'.

ERROR [SQL Native Client][SQL Server]The statement has been terminated.

at System.Data.Odbc.OdbcConnection.HandleError(OdbcHandle hrHandle, RetCode retcode)

at System.Data.Odbc.OdbcCommand.ExecuteReaderObject(CommandBehavior behavior, String method, Boolean needReader, Object[] methodArguments, SQL_API odbcApiMethod)

at System.Data.Odbc.OdbcCommand.ExecuteReaderObject(CommandBehavior behavior, String method, Boolean needReader)

at System.Data.Odbc.OdbcCommand.ExecuteNonQuery()

at NHibernate.Impl.NonBatchingBatcher.AddToBatch(IExpectation expectation)

at NHibernate.Persister.Entity.AbstractEntityPersister.Insert(Object id, Object[] fields, Boolean[] notNull, Int32 j, SqlCommandInfo sql, Object obj, ISessionImplementor session)

End of inner exception stack trace ---

at NHibernate.Persister.Entity.AbstractEntityPersister.Insert(Object id, Object[] fields, Boolean[] notNull, Int32 j, SqlCommandInfo sql, Object obj, ISessionImplementor session)

at NHibernate.Persister.Entity.AbstractEntityPersister.Insert(Object id, Object[] fields, Object obj, ISessionImplementor session)

at NHibernate.Impl.ScheduledInsertion.Execute()

at NHibernate.Impl.SessionImpl.Execute(IExecutable executable)

at NHibernate.Impl.SessionImpl.ExecuteAll(IList list)

at NHibernate.Impl.SessionImpl.Execute()

at NHibernate.Impl.SessionImpl.Flush()

at NHibernate.Transaction.AdoTransaction.Commit()

at VMware.Sim.ServiceCore.Persistence.Database.SimDbTransaction.Commit()

End of inner exception stack trace ---, Machine Name: VC, Timestamp: 12/12/2008 3:44:42 AM, App Domain Name: SviWebService.exe, Thread Identity: , Windows Identity: NT AUTHORITY\SYSTEM, OS Version: Microsoft Windows NT 5.2.3790 Service Pack 2, reason: UniqueConstraintViolation

2008-12-11 21:44:42,143 | 24 | INFO | Persistence.Database.SimDbTransaction - Implicit rollback performed.

2008-12-11 21:44:42,143 | 24 | ERROR | NHibernate.Util.ADOExceptionReporter - ERROR [SQL Native Client][SQL Server]Violation of PRIMARY KEY constraint 'PK_SVI_COMPUTER_NAME'. Cannot insert duplicate key in object 'dbo.SVI_COMPUTER_NAME'.

ERROR [SQL Native Client][SQL Server]The statement has been terminated.

2008-12-11 21:44:42,143 | 24 | ERROR | NHibernate.Impl.SessionImpl - could not synchronize database state with session

NHibernate.ADOException: could not insert: http://VMware.Sim.ServiceCore.DataObject.GuestComputerNameDo#VMware.Sim.ServiceCore.DataObject.Guest...[SQL: INSERT INTO SVI_COMPUTER_NAME (FQDN, NAME) VALUES (?, ?)] ---> System.Data.Odbc.OdbcException: ERROR [SQL Native Client][SQL Server]Violation of PRIMARY KEY constraint 'PK_SVI_COMPUTER_NAME'. Cannot insert duplicate key in object 'dbo.SVI_COMPUTER_NAME'.

ERROR [SQL Native Client][SQL Server]The statement has been terminated.

at System.Data.Odbc.OdbcConnection.HandleError(OdbcHandle hrHandle, RetCode retcode)

at System.Data.Odbc.OdbcCommand.ExecuteReaderObject(CommandBehavior behavior, String method, Boolean needReader, Object[] methodArguments, SQL_API odbcApiMethod)

at System.Data.Odbc.OdbcCommand.ExecuteReaderObject(CommandBehavior behavior, String method, Boolean needReader)

at System.Data.Odbc.OdbcCommand.ExecuteNonQuery()

at NHibernate.Impl.NonBatchingBatcher.AddToBatch(IExpectation expectation)

at NHibernate.Persister.Entity.AbstractEntityPersister.Insert(Object id, Object[] fields, Boolean[] notNull, Int32 j, SqlCommandInfo sql, Object obj, ISessionImplementor session)

End of inner exception stack trace ---

at NHibernate.Persister.Entity.AbstractEntityPersister.Insert(Object id, Object[] fields, Boolean[] notNull, Int32 j, SqlCommandInfo sql, Object obj, ISessionImplementor session)

at NHibernate.Persister.Entity.AbstractEntityPersister.Insert(Object id, Object[] fields, Object obj, ISessionImplementor session)

at NHibernate.Impl.ScheduledInsertion.Execute()

at NHibernate.Impl.SessionImpl.Execute(IExecutable executable)

at NHibernate.Impl.SessionImpl.ExecuteAll(IList list)

at NHibernate.Impl.SessionImpl.Execute()

2008-12-11 21:44:42,143 | 24 | FATAL | ServiceCore.Persistence.TranCollector -

TranId:dce12b60-0a9b-4ede-92b6-1f7983fd924d, queries:Transaction before commit

Stack Trace:

GetStackTrace

Add

Commit

SaveObjectArray

SaveComputerName

SetUniqueNames

.ctor

CreateSviClones

SyncInvokeCreateSviClones

Invoke

InvokeBegin

ProcessMessage5

ProcessMessage4

ProcessMessage3

ProcessMessage2

ProcessMessage1

Process

DispatchAndReleasePump

HandleRequest

AsyncMessagePump

OnAsyncReceiveComplete

UnhandledExceptionFrame

Complete

Set

EnqueueAndDispatch

Enqueue

HttpContextReceived

OnGetContextCore

OnGetContext

UnhandledExceptionFrame

Complete

ProtectedInvokeCallback

WaitCallback

PerformIOCompletionCallback

Stack Trace:

GetStackTrace

Log

Commit

SaveObjectArray

SaveComputerName

SetUniqueNames

.ctor

CreateSviClones

SyncInvokeCreateSviClones

Invoke

InvokeBegin

ProcessMessage5

ProcessMessage4

ProcessMessage3

ProcessMessage2

ProcessMessage1

Process

DispatchAndReleasePump

HandleRequest

AsyncMessagePump

OnAsyncReceiveComplete

UnhandledExceptionFrame

Complete

Set

EnqueueAndDispatch

Enqueue

HttpContextReceived

OnGetContextCore

OnGetContext

UnhandledExceptionFrame

Complete

ProtectedInvokeCallback

WaitCallback

PerformIOCompletionCallback

2008-12-11 21:44:42,143 | 24 | FATAL | ServiceCore.Persistence.SimDaoHelper - Log and throw: Hibernate threw exception during Commit.

NHibernate.ADOException: could not insert: http://VMware.Sim.ServiceCore.DataObject.GuestComputerNameDo#VMware.Sim.ServiceCore.DataObject.Guest...[SQL: INSERT INTO SVI_COMPUTER_NAME (FQDN, NAME) VALUES (?, ?)] ---> System.Data.Odbc.OdbcException: ERROR [SQL Native Client][SQL Server]Violation of PRIMARY KEY constraint 'PK_SVI_COMPUTER_NAME'. Cannot insert duplicate key in object 'dbo.SVI_COMPUTER_NAME'.

ERROR [SQL Native Client][SQL Server]The statement has been terminated.

at System.Data.Odbc.OdbcConnection.HandleError(OdbcHandle hrHandle, RetCode retcode)

at System.Data.Odbc.OdbcCommand.ExecuteReaderObject(CommandBehavior behavior, String method, Boolean needReader, Object[] methodArguments, SQL_API odbcApiMethod)

at System.Data.Odbc.OdbcCommand.ExecuteReaderObject(CommandBehavior behavior, String method, Boolean needReader)

at System.Data.Odbc.OdbcCommand.ExecuteNonQuery()

at NHibernate.Impl.NonBatchingBatcher.AddToBatch(IExpectation expectation)

at NHibernate.Persister.Entity.AbstractEntityPersister.Insert(Object id, Object[] fields, Boolean[] notNull, Int32 j, SqlCommandInfo sql, Object obj, ISessionImplementor session)

End of inner exception stack trace ---

at NHibernate.Persister.Entity.AbstractEntityPersister.Insert(Object id, Object[] fields, Boolean[] notNull, Int32 j, SqlCommandInfo sql, Object obj, ISessionImplementor session)

at NHibernate.Persister.Entity.AbstractEntityPersister.Insert(Object id, Object[] fields, Object obj, ISessionImplementor session)

at NHibernate.Impl.ScheduledInsertion.Execute()

at NHibernate.Impl.SessionImpl.Execute(IExecutable executable)

at NHibernate.Impl.SessionImpl.ExecuteAll(IList list)

at NHibernate.Impl.SessionImpl.Execute()

at NHibernate.Impl.SessionImpl.Flush()

at NHibernate.Transaction.AdoTransaction.Commit()

at VMware.Sim.ServiceCore.Persistence.Database.SimDbTransaction.Commit()

2008-12-11 21:44:42,143 | 24 | FATAL | ServiceCore.Persistence.SimDaoHelper - A DAO exception is thrown:

VMware.Sim.ServiceCore.Exception.SimDaoException: [SQL Native Client][SQL Server]Violation of PRIMARY KEY constraint 'PK_SVI_COMPUTER_NAME'. Cannot insert duplicate key in object 'dbo.SVI_COMPUTER_NAME'. ---> NHibernate.ADOException: could not insert: http://VMware.Sim.ServiceCore.DataObject.GuestComputerNameDo#VMware.Sim.ServiceCore.DataObject.Guest...[SQL: INSERT INTO SVI_COMPUTER_NAME (FQDN, NAME) VALUES (?, ?)] ---> System.Data.Odbc.OdbcException: ERROR [SQL Native Client][SQL Server]Violation of PRIMARY KEY constraint 'PK_SVI_COMPUTER_NAME'. Cannot insert duplicate key in object 'dbo.SVI_COMPUTER_NAME'.

ERROR [SQL Native Client][SQL Server]The statement has been terminated.

at System.Data.Odbc.OdbcConnection.HandleError(OdbcHandle hrHandle, RetCode retcode)

at System.Data.Odbc.OdbcCommand.ExecuteReaderObject(CommandBehavior behavior, String method, Boolean needReader, Object[] methodArguments, SQL_API odbcApiMethod)

at System.Data.Odbc.OdbcCommand.ExecuteReaderObject(CommandBehavior behavior, String method, Boolean needReader)

at System.Data.Odbc.OdbcCommand.ExecuteNonQuery()

at NHibernate.Impl.NonBatchingBatcher.AddToBatch(IExpectation expectation)

at NHibernate.Persister.Entity.AbstractEntityPersister.Insert(Object id, Object[] fields, Boolean[] notNull, Int32 j, SqlCommandInfo sql, Object obj, ISessionImplementor session)

End of inner exception stack trace ---

at NHibernate.Persister.Entity.AbstractEntityPersister.Insert(Object id, Object[] fields, Boolean[] notNull, Int32 j, SqlCommandInfo sql, Object obj, ISessionImplementor session)

at NHibernate.Persister.Entity.AbstractEntityPersister.Insert(Object id, Object[] fields, Object obj, ISessionImplementor session)

at NHibernate.Impl.ScheduledInsertion.Execute()

at NHibernate.Impl.SessionImpl.Execute(IExecutable executable)

at NHibernate.Impl.SessionImpl.ExecuteAll(IList list)

at NHibernate.Impl.SessionImpl.Execute()

at NHibernate.Impl.SessionImpl.Flush()

at NHibernate.Transaction.AdoTransaction.Commit()

at VMware.Sim.ServiceCore.Persistence.Database.SimDbTransaction.Commit()

End of inner exception stack trace ---, Machine Name: VC, Timestamp: 12/12/2008 3:44:42 AM, App Domain Name: SviWebService.exe, Thread Identity: , Windows Identity: NT AUTHORITY\SYSTEM, OS Version: Microsoft Windows NT 5.2.3790 Service Pack 2, reason: UniqueConstraintViolation

2008-12-11 21:44:42,143 | 24 | INFO | Persistence.Database.SimDbTransaction - Implicit rollback performed.

2008-12-11 21:44:42,143 | 24 | INFO | ServiceCore.Action.UfaInitializeDiskAction - Created an UfaInitializeDiskAction with total disks 1.

2008-12-11 21:44:42,143 | 24 | INFO | ServiceCore.LockManager.LockManager - Multiple lock are required for SimClone with ids:

2008-12-11 21:44:44,948 | VC thread | INFO | ServiceCore.Action.CreateLinkedCloneVcAction - Linked Clone created with dsPath: xppc5/xppc5.vmx

2008-12-11 21:44:46,288 | VC thread | INFO | ServiceCore.Action.RegisterVmVcAction - Linked Clone created with VM MoId: vm-234

2008-12-11 21:44:46,459 | WFE thread 6 | INFO | ServiceCore.ActiveDirectory.AdUtil - Attempting to add a computer account using DC 1 of 1

2008-12-11 21:44:46,677 | WFE thread 6 | INFO | ServiceCore.ActiveDirectory.AdUtil - New computer account has been created successfully.

2008-12-11 21:44:49,778 | UFA thread 1 | INFO | CommonLib.VcSubsystem.VcSubsystem25 - Getting NFC ticket for disk 2001 in vm vm-234

2008-12-11 21:44:49,871 | UFA thread 1 | INFO | CommonLib.VcSubsystem.VcSubsystem25 - Recevied the NFC ticket for disk 2001 in vm vm-234 from VC.

2008-12-11 21:44:49,871 | UFA thread 1 | INFO | CommonLib.UfaSubsystem.UfaWorkItem - UFA: issuing disk connection request to UFA service for disk: datastore: xppc5/xppc5-vdm-user-disk-U.vmdk, host: esx2.lab.local, port: 902

2008-12-11 21:44:50,697 | UFA thread 1 | INFO | CommonLib.UfaSubsystem.UfaWorkItem - UFA: partitioning the disk: datastore: xppc5/xppc5-vdm-user-disk-U.vmdk, host: esx2.lab.local, port: 902

2008-12-11 21:44:50,868 | UFA thread 1 | INFO | CommonLib.UfaSubsystem.UfaWorkItem - UFA: formatting the disk: datastore: xppc5/xppc5-vdm-user-disk-U.vmdk, host: esx2.lab.local, port: 902

2008-12-11 21:44:56,742 | UFA thread 1 | INFO | CommonLib.UfaSubsystem.UfaWorkItem - UFA: start creating2 files on the disk: datastore: xppc5/xppc5-vdm-user-disk-U.vmdk, host: esx2.lab.local, port: 902

2008-12-11 21:44:56,742 | UFA thread 1 | INFO | CommonLib.UfaSubsystem.UfaWorkItem - UFA: start creating file:
.\vstor2-ufa-7B000000007E00000000000002000000\simvol.dat

2008-12-11 21:44:56,757 | UFA thread 1 | INFO | CommonLib.UfaSubsystem.UfaWorkItem - UFA: start creating file:
.\vstor2-ufa-7B000000007E00000000000002000000\sim.dat

2008-12-11 21:44:56,773 | UFA thread 1 | INFO | CommonLib.UfaSubsystem.UfaWorkItem - UFA: finish init disk operation for disk: datastore: xppc5/xppc5-vdm-user-disk-U.vmdk, host: esx2.lab.local, port: 902 successfully.

2008-12-11 21:44:57,832 | UFA thread 1 | INFO | ServiceCore.Action.UfaInitializeDiskAction - UfaInitializeDiskAction: finished init disk: xppc5/xppc5-vdm-user-disk-U.vmdk.

2008-12-11 21:44:57,864 | WFE thread 9 | INFO | ServiceCore.LockManager.LockManager - Multiple releases are reuiqred for SimClone with ids:

2008-12-11 21:44:57,864 | WFE thread 9 | INFO | ServiceCore.LockManager.LockManager - A release is requested for DeploymentGroup with id: a1c079b1-7f97-4b18-a350-7470a644ebb7

and now it just sits at customizing for about 6 minutes. nothing additional is ever logged in the above log about the state changing from customizing to ready.

Under the "Events" on my View Admin, these are the last two events.

Message: Pool control for desktop xp_pool is starting VM xppc5

Type: Info

Time: 12/11/08 9:44:59 PM

Module: PendingOperation

Thread: PendingOperation-/LAB DC/vm/xp_pool/xppc5

.

Message: STARTUP:Server:cn=56eee3f2-bc75-4419-9ca2-7e73ecf7eb7e,ou=servers,dc=vdi,dc=vmware,dc=int;Pool:cn=xp_pool,ou=server groups,dc=vdi,dc=vmware,dc=int;DNS

Type: Info

Time: 12/11/08 9:51:16 PM

Module: Audit

Thread: PoolManager

Additional details:

STARTUP:Server:cn=56eee3f2-bc75-4419-9ca2-7e73ecf7eb7e,ou=servers,dc=vdi,dc=vmware,dc=int;Pool:cn=xp_pool,ou=server groups,dc=vdi,dc=vmware,dc=int;DNS:xppc5.lab.local;IP:192.168.1.5;

Notice the time stamp, about 6 minutes. Thanks

-Craig

TomHowarth · ‎12-12-2008

Moved to the VMware View Manager Forum

Tom Howarth

VMware Communities User Moderator

Blog: www.planetvm.net

Tom Howarth VCP / VCAP / vExpert
VMware Communities User Moderator
Blog: http://www.planetvm.net
Contributing author on VMware vSphere and Virtual Infrastructure Security: Securing ESX and the Virtual Environment
Contributing author on VCP VMware Certified Professional on VSphere 4 Study Guide: Exam VCP-410

corihoni · ‎01-13-2009

did you find any sucessful solution? because i had the same problem on my vm view test environment. the new created vm's in the linked clone pool take about 5-8 minutes just for customizing. i tried the posted solutions but it still doesn't work as fast as it should. thanks

cdickerson · ‎01-13-2009

yeah I did. My local VMware SE was able to provide me this info. Here is a portion of his email.

There is a bug in Windows related to the PnP driver for the User Data Disk that forces the reboot. We default to 5 minutes. So, don't try to login until the system shows ready in the View web GUI.

If you have fast enough hardware you can tweak the timeout. The timeout for which we will wait for the PnP service to install the new hardware is configurable. Currently it is set to be 5 minutes. You can set it in the master VM (for the purpose of demoing it) by setting a registry value PnPTimeout in Create a new decimal value for the wait time. The key must be called PnPTimeout. The value is in seconds, and if you're sure that your systems are fast you can change it to a minute (or less). The reason we set it to be 5 minutes is that on the reference deployment system (set up by the VDI system test) it took that much time for the PnP service to start and install the new hardware.

I am using 90 seconds and it appears to be just the right setting in my environment.

-Craig

corihoni · ‎02-13-2009

Thank you!! It accelerates my customizing from 10 minutes to 5 now it's just the f** vista which takes about 4 to 5 minutes to start.