Logon times

sappomannoz · ‎06-17-2015

Hello,

it's normal the attaching 5 appstacks delays the login for an additional 30-30 second?

I have tested with and whiteout the broker integration service

- with the broker integration service I wait up to 30 seconds for the to be presented with the login screen, then the login goes quite fast

- w/o broker integration service the desktops connects in seconds but the login takes 45/50 seconds

appstacks are connected via ESXi hosts and the Datastore is local on SSD. Are those times expected and normal?

KR

Cristiano

Ray_handels · ‎06-17-2015

I believe that they are always working on trying to enhance login speed.

What we see happening now is that, when reconfiguring the machine, it takes about 30 seconds to reconfigure in VCenter wereas this normally was done within a few seconds. If we only have 1 appstack it does take just a few seconds to reconfigure in VCenter. Then, if attached login only takes up to 30 seconds with 1 appstack attached.

I normally see an increase of 1 to 2 seconds per extra appstack. If you have more than 30 seconds delay per appstack it times out when connecting (30 seconds is default timeout value) I guess there is an issue with the appstack then?

If no writable volume is attached first time login will also be slower due to windows creating a profile for you based on the default profile. This could add up to 10 to 15 seconds extra.

sappomannoz · ‎06-17-2015

Hi Ray,

I'm using Persona Manager and VMware EUM in my POC, so, the profile creation happens just the first time an user logs in.

I have seen that it takes 25 seconds for the ESXi host or VCenter just to attach the volumes, and I think I have to live with that. I don't think there is a way to speedup the host reconfiguration.

With broker integration it takes 60 second to log in 33 spent connecting and 27 logging in.

W/o broker integration it takes... 61 seconds to log in

No big difference

Cristiano

Mount on Host

Mount via VCenter

Ray_handels · ‎06-17-2015

See, i knew we were not the only ones... No the reconfigure of 25 seconds isn't normal.

When we tested with VSphere 5.5 and Appvolumes 2.5 the reconfigure was done in just about 2 seconds, regardless the number of appstacks.. We still have an open case regarding this issue and looking into a fix for it. No idea if you have support for it or just testing it but otherwise, please raise an SR with VMware regarding the reconfigure issue. As said. It should be done within 2 seconds.I sure as hell don't really want to live with it

I'm using Persona Manager and VMware EUM in my POC, so, the profile creation happens just the first time an user logs in.

For me this is the big discussion we are having now with the newly released info regarding writable volumes. I would normally not suggest using Persona Manager and EUM because Appvolumes UIA + Profiles does both within 1 writable volume. It simplifies management hugely because you can let the user install applications and even save his settings in the writable volume without you needing to worry about it in any way. Also zero management, no FlexProfiles console (it is Immidio's FelxProfiles solution) and another setup for Persona Management. Just create the writable volume on a user base and off you go..

With broker integration it takes 60 second to log in 33 spent connecting and 27 logging in.

W/o broker integration it takes... 61 seconds to log in

Thing is that it needs to be 27 logging in and 2 to 3 reconfiguing the machine, thus being about 30 seconds. And then you need to start counting about 1 or 2 seconds (depending on size) for an extra appstack.

sappomannoz · ‎06-18-2015

Hi Ray

I will open a SR and perform some tests with vSphere 5.5. Could you also send me the SR # so that I can reference it in mine?

Regarding VMware EUM vs Appvolumes wiritabe, it depends. If you need multiple logins or also use RSDH then EUM becomes interesting.

Ray_handels · ‎06-18-2015

SR is 15643522404.

There is another topic where this is discussed and JHT_Seatlle said that when he created the golden image on the VSphere 6.0 enviornment reconfigures did went good. We did copy the golden image from 5.5 to 6.0 but I've also tested with a newly created golden image on 6.0 and to no avail. My guess is it seems to be some sort of command that is being send to Vcenter that it can't cope with. Just my 2 cents though .

And regarding the RDSH. I do see the benefit of FlexProfiles in mixed enviornments but i would have loved to see it as an addition to the Writable volume, not a replacement. The problem with FlexProfiles (or Appsense or Microsoft UEV or any profile management tool other than the buggy roaming profile windows uses) is that you need to configure the client and tell it which settings it should record. If a user installs an application himself you cannot trace changes made to the applications. Also, for as far as I'm aware, you can only use the roaming part of the profile (the APPDATA) within these tools, not the LOCALAPPDATA. Plus, we have quite the applications that we deliver (over 200) and you would need to configure each manually..

sappomannoz · ‎06-18-2015

Hi Ray,

My SR is 15691791206

It seems a problem on the host:

2015-06-18T07:49:28.809Z info hostd[23081B70] [Originator@6876 sub=Vimsvc.TaskManager opID=2de4d5e4-2e-525b user=vpxuser:XXXXX\xx_xxxxxxxxxxx_admin] Task Created : haTask-197-vim.VirtualMachine.reconfigure-2427658

2015-06-18T07:49:28.810Z info hostd[250C1B70] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/55684f2d-bab70d39-c27d-0025b513e28e/acd007edo/acd007edo.vmx opID=2de4d5e4-2e-525b user=vpxuser:XXXXX\xx_xxxxxxxxxxx_admin] State Transition (VM_STATE_ON -> VM_STATE_RECONFIGURING)

2015-06-18T07:49:33.711Z info hostd[243C5B70] [Originator@6876 sub=Hostsvc opID=f3da5267] VsanSystemVmkProvider : GetRuntimeInfo: Complete, runtime info: (vim.vsan.host.VsanRuntimeInfo) {

--> accessGenNo = 0,

--> }

2015-06-18T07:49:51.821Z info hostd[247C1B70] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/55684f2d-bab70d39-c27d-0025b513e28e/acd007edo/acd007edo.vmx opID=2de4d5e4-2e-525b user=vpxuser:XXXXX\xx_xxxxxxxxxxx_admin] State Transition (VM_STATE_RECONFIGURING -> VM_STATE_ON)

2015-06-18T07:49:51.821Z info hostd[23D40B70] [Originator@6876 sub=Guestsvc.GuestFileTransferImpl] Entered VmPowerStateListener

2015-06-18T07:49:51.821Z info hostd[23D40B70] [Originator@6876 sub=Guestsvc.GuestFileTransferImpl] VmPowerStateListener succeeded

2015-06-18T07:49:51.821Z info hostd[23D40B70] [Originator@6876 sub=Hbrsvc] Replicator: powerstate change VM: 197 Old: 1 New: 1

2015-06-18T07:49:51.822Z info hostd[247C1B70] [Originator@6876 sub=Vimsvc.ha-eventmgr opID=2de4d5e4-2e-525b user=vpxuser:XXXXX\xx_xxxxxxxxxxx_admin] Event 27612 : Reconfigured acd007edo on sdcesx19.unibz.it in ha-datacenter

2015-06-18T07:49:51.822Z info hostd[247C1B70] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/55684f2d-bab70d39-c27d-0025b513e28e/acd007edo/acd007edo.vmx opID=2de4d5e4-2e-525b user=vpxuser:XXXXX\xx_xxxxxxxxxxx_admin] Send config update invoked

The entry regarding Vsan is a mystery, since it's not enabled.

Yes, it's always better to have more than on option, I agree with that. The beauty of Immidio is the ability of migrate apps settings form roaming profiles. If you are managing an app via Immidio the entries in the profile are cleaned up, freeing space . This way if an user installs a program that is currently not known by Immidio it gets managed via roaming profile/persona management, until you create a UEM template.

Ray_handels · ‎06-18-2015

This is very interesting. We don't have VSAN enabled either.

I send the information to VMWare so hopefully they might just have a solution for us.

Could it be that you need to disable the VSAN service in some way on the host itself? As VSAN is enabled per cluster and not really configurable there?

sappomannoz · ‎06-18-2015

Hi,

VSAN could be a red herring. Looking at the VPXA logs one sees that the disks are processed one after another and it takes some times per task. At the end of the logs you can see 2/3 seconds per task.

This is the log for 4 appstacks, but it takes a lot of updates to process them

015-06-18T10:04:59.720Z verbose vpxa[6E0B5B70] [Originator@6876 sub=vpxTaskInfo opID=SWI-6e4b8ab1] [TaskInfoChannel::GetTaskInfoHandleSuccess] task: haTask-199-vim.VirtualMachine.reconfigure-2436770 updated to version 1(known last version = 0)

2015-06-18T10:04:59.720Z verbose vpxa[6E0D6B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-7a053e84] [WaitForUpdatesDone] Completed callback

2015-06-18T10:04:59.888Z verbose vpxa[FFBCEA60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-171568ff] [WaitForUpdatesDone] Received callback

2015-06-18T10:04:59.888Z verbose vpxa[FFBCEA60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-171568ff] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 1490940 to 1490942 (at 1490940)

2015-06-18T10:04:59.888Z verbose vpxa[FFBCEA60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-171568ff] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2015-06-18T10:04:59.888Z verbose vpxa[FFBCEA60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-171568ff] [WaitForUpdatesDone] Completed callback

2015-06-18T10:04:59.893Z verbose vpxa[FFBCEA60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-7ea0492f] [WaitForUpdatesDone] Received callback

2015-06-18T10:04:59.893Z verbose vpxa[FFBCEA60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-7ea0492f] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 1490942 to 1490943 (at 1490942)

2015-06-18T10:04:59.893Z verbose vpxa[FFBCEA60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-7ea0492f] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2015-06-18T10:04:59.893Z verbose vpxa[FFBCEA60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-7ea0492f] [WaitForUpdatesDone] Completed callback

2015-06-18T10:05:00.033Z verbose vpxa[6E139B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-4d24ed9b] [WaitForUpdatesDone] Received callback

2015-06-18T10:05:00.033Z verbose vpxa[6E139B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-4d24ed9b] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 1490943 to 1490944 (at 1490943)

2015-06-18T10:05:00.033Z verbose vpxa[6E139B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-4d24ed9b] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2015-06-18T10:05:00.033Z verbose vpxa[6E139B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-4d24ed9b] [WaitForUpdatesDone] Completed callback

2015-06-18T10:05:00.118Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-336b82ae] [WaitForUpdatesDone] Received callback

2015-06-18T10:05:00.118Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-336b82ae] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 1490944 to 1490945 (at 1490944)

2015-06-18T10:05:00.118Z verbose vpxa[6E0B5B70] [Originator@6876 sub=hostdvm opID=WFU-336b82ae] [VpxaHalVmHostagent] 196: GuestInfo changed 'guest.disk'

2015-06-18T10:05:00.118Z verbose vpxa[6E0B5B70] [Originator@6876 sub=halservices opID=WFU-336b82ae] [VpxaHalServices] VmGuestDiskChange Event for vm(197) 196

2015-06-18T10:05:00.118Z verbose vpxa[6E0B5B70] [Originator@6876 sub=vpxaInvtVm opID=WFU-336b82ae] [VpxaInvtVmChangeListener] Guest DiskInfo Changed

2015-06-18T10:05:00.118Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-336b82ae] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2015-06-18T10:05:00.118Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-336b82ae] [WaitForUpdatesDone] Completed callback

2015-06-18T10:05:00.123Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-575087e1] [WaitForUpdatesDone] Received callback

2015-06-18T10:05:00.123Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-575087e1] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 1490945 to 1490946 (at 1490945)

2015-06-18T10:05:00.123Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-575087e1] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2015-06-18T10:05:00.123Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-575087e1] [WaitForUpdatesDone] Completed callback

2015-06-18T10:05:00.184Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-6808f18f] [WaitForUpdatesDone] Received callback

2015-06-18T10:05:00.184Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-6808f18f] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 1490946 to 1490947 (at 1490946)

2015-06-18T10:05:00.184Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-6808f18f] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2015-06-18T10:05:00.184Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-6808f18f] [WaitForUpdatesDone] Completed callback

2015-06-18T10:05:00.576Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-232b18a5] [WaitForUpdatesDone] Received callback

2015-06-18T10:05:00.576Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-232b18a5] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 1490947 to 1490948 (at 1490947)

2015-06-18T10:05:00.576Z verbose vpxa[6E0B5B70] [Originator@6876 sub=hostdvm opID=WFU-232b18a5] [VpxaHalVmHostagent] 253: GuestInfo changed 'guest.disk'

2015-06-18T10:05:00.576Z verbose vpxa[6E0B5B70] [Originator@6876 sub=halservices opID=WFU-232b18a5] [VpxaHalServices] VmGuestDiskChange Event for vm(254) 253

2015-06-18T10:05:00.576Z verbose vpxa[6E0B5B70] [Originator@6876 sub=vpxaInvtVm opID=WFU-232b18a5] [VpxaInvtVmChangeListener] Guest DiskInfo Changed

2015-06-18T10:05:00.576Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-232b18a5] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2015-06-18T10:05:00.576Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-232b18a5] [WaitForUpdatesDone] Completed callback

2015-06-18T10:05:02.696Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-625f0aac] [WaitForUpdatesDone] Received callback

2015-06-18T10:05:02.696Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-625f0aac] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 1490948 to 1490949 (at 1490948)

2015-06-18T10:05:02.696Z verbose vpxa[6E0B5B70] [Originator@6876 sub=hostdvm opID=WFU-625f0aac] [VpxaHalVmHostagent] 199: GuestInfo changed 'guest.disk'

2015-06-18T10:05:02.696Z verbose vpxa[6E0B5B70] [Originator@6876 sub=halservices opID=WFU-625f0aac] [VpxaHalServices] VmGuestDiskChange Event for vm(200) 199

2015-06-18T10:05:02.696Z verbose vpxa[6E0B5B70] [Originator@6876 sub=vpxaInvtVm opID=WFU-625f0aac] [VpxaInvtVmChangeListener] Guest DiskInfo Changed

2015-06-18T10:05:02.696Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-625f0aac] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2015-06-18T10:05:02.696Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-625f0aac] [WaitForUpdatesDone] Completed callback

2015-06-18T10:05:02.706Z verbose vpxa[6E139B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-4db5d4a8] [WaitForUpdatesDone] Received callback

2015-06-18T10:05:02.707Z verbose vpxa[6E139B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-4db5d4a8] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 1490949 to 1490950 (at 1490949)

2015-06-18T10:05:02.707Z verbose vpxa[6E139B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-4db5d4a8] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2015-06-18T10:05:02.707Z verbose vpxa[6E139B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-4db5d4a8] [WaitForUpdatesDone] Completed callback

2015-06-18T10:05:04.107Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-5c9c8973] [WaitForUpdatesDone] Received callback

2015-06-18T10:05:04.107Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-5c9c8973] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 1490950 to 1490951 (at 1490950)

2015-06-18T10:05:04.107Z verbose vpxa[6E0B5B70] [Originator@6876 sub=hostdvm opID=WFU-5c9c8973] [VpxaHalVmHostagent] 251: GuestInfo changed 'guest.disk'

2015-06-18T10:05:04.107Z verbose vpxa[6E0B5B70] [Originator@6876 sub=halservices opID=WFU-5c9c8973] [VpxaHalServices] VmGuestDiskChange Event for vm(252) 251

2015-06-18T10:05:04.107Z verbose vpxa[6E0B5B70] [Originator@6876 sub=vpxaInvtVm opID=WFU-5c9c8973] [VpxaInvtVmChangeListener] Guest DiskInfo Changed

2015-06-18T10:05:04.107Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-5c9c8973] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2015-06-18T10:05:04.107Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-5c9c8973] [WaitForUpdatesDone] Completed callback

2015-06-18T10:05:04.729Z verbose vpxa[6E0D6B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-29040c85] [WaitForUpdatesDone] Received callback

2015-06-18T10:05:04.729Z verbose vpxa[6E0D6B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-29040c85] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 1490951 to 1490952 (at 1490951)

2015-06-18T10:05:04.729Z verbose vpxa[6E0D6B70] [Originator@6876 sub=vpxaTaskInfo opID=WFU-29040c85] [VpxaTaskInfoPublisher::PropertyChanged] Number of deferred task updates: 0

2015-06-18T10:05:04.729Z verbose vpxa[6E0D6B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-29040c85] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2015-06-18T10:05:04.729Z verbose vpxa[6E139B70] [Originator@6876 sub=vpxTaskInfo opID=SWI-48d204cc] [TaskInfoChannel::GetTaskInfoHandleSuccess] task: haTask-199-vim.VirtualMachine.reconfigure-2436770 updated to version 2(known last version = 1)

2015-06-18T10:05:04.730Z verbose vpxa[6E139B70] [Originator@6876 sub=PropertyProvider opID=SWI-48d204cc] RecordOp ASSIGN: info.progress, task-200287. Applied change to temp map.

2015-06-18T10:05:04.730Z verbose vpxa[6E0D6B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-29040c85] [WaitForUpdatesDone] Completed callback

2015-06-18T10:05:04.730Z verbose vpxa[6E139B70] [Originator@6876 sub=PropertyProvider opID=SWI-48d204cc] [CommitChangesAndNotify] Updating cached values

2015-06-18T10:05:05.211Z verbose vpxa[6E0D6B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-6ee8dd4d] [WaitForUpdatesDone] Received callback

2015-06-18T10:05:05.211Z verbose vpxa[6E0D6B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-6ee8dd4d] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 1490952 to 1490953 (at 1490952)

2015-06-18T10:05:05.211Z verbose vpxa[6E0D6B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-6ee8dd4d] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2015-06-18T10:05:05.211Z verbose vpxa[6E0D6B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-6ee8dd4d] [WaitForUpdatesDone] Completed callback

2015-06-18T10:05:05.237Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-7a19231d] [WaitForUpdatesDone] Received callback

2015-06-18T10:05:05.237Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-7a19231d] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 1490953 to 1490954 (at 1490953)

2015-06-18T10:05:05.237Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-7a19231d] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2015-06-18T10:05:05.237Z verbose vpxa[6E0B5B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-7a19231d] [WaitForUpdatesDone] Completed callback

2015-06-18T10:05:06.810Z verbose vpxa[6E139B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-850838b] [WaitForUpdatesDone] Received callback

2015-06-18T10:05:06.810Z verbose vpxa[6E139B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-850838b] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 1490954 to 1490955 (at 1490954)

2015-06-18T10:05:06.810Z verbose vpxa[6E139B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-850838b] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2015-06-18T10:05:06.810Z verbose vpxa[6E139B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-850838b] [WaitForUpdatesDone] Completed callback

2015-06-18T10:05:08.461Z verbose vpxa[6DE31B70] [Originator@6876 sub=vpxaMoVm opID=SWI-41a7] [VpxaMoVm::CheckMoVm] did not find a VM with ID 257 in the vmList

2015-06-18T10:05:08.462Z verbose vpxa[6DE31B70] [Originator@6876 sub=Alarm opID=SWI-41a7] [VpxaAlarm] VM with vmid = 257 not found

2015-06-18T10:05:10.518Z verbose vpxa[6E0D6B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-5dec1ef0] [WaitForUpdatesDone] Received callback

Ray_handels · ‎06-18-2015

But this is quite strange because if we only have 1 appstack reconfigure is done within a few seconds.

The moment we have more than 1 appstack reconfigure time increases hugely. But having 2 or 5 or 8 appstacks doesn't make that much of a difference to be honest.

The Appvolumes logging is on the management server in the folder C:\Program Files (x86)\CloudVolumes\Manager\log\production.log. Do you see the same timeframe in both of these loggings? What we saw in the Appvolumes production.log is that there is a "hole" of over 20 seconds when the reconfigure takes place. Only thing VCenter needs to do is attach a few disks. Normally it should not be taking this long. Appvolumes filterdriver than, after appstacks are attached, starts merging the appstacks within the golden image and executing startup.bat files and stuff like that.

sappomannoz · ‎07-15-2015

Hello Ray,

did you get any news on the issue? I had a problem with NTP but fixing it didn't fix the issue

Cristiano

Ray_handels · ‎07-15-2015

Hey Cristiano,

Exactly the same issue here, we also had a time difference between the Vcenter and ESX hosts. We do see a small improvement in reconfigure speed but still not enough.

What we see know is that it takes up to 3,5 seconds to attach a VMDK so when a user has 7 appstacks and a writeble volume reconfigure time is somewhere in the 25 to 30 seconds reconfigure range.

We are putting the pressure on to be honest cause this needs to be fixed one way or the other. As said, in our old 5.1 VSphere enviornment we didn't have these issues.

I wil keep you updated if we find a cause for it.

sappomannoz · ‎07-16-2015

Hmm, I could go back to ESX 5.5 as I don't currently use vGPU features and keep VCenter 6.

Ray_handels · ‎07-16-2015

It could be worth a try. Would love to hear if it works with that one.

For as far as i can se now what happens is that each disk is added to the machine on an individual basis which means a reconfigure per disks.

What i would like to see is a reconfigure of the entire machine all at once. I think that reconfiguring a machine should not take more that 5 or at a max 10 seconds.

anvr · ‎07-16-2015

Hello,

Our environment:

ESX 6.0.0,2809209

vCenter Appliance 6.0.0.5120

App-Volumes 2.9

Use Windows Roaming profiles.

Config: Appstack attached directly on ESX host (no entries in vsphere when adding appvol HDD's)

Login w/o Appstack (select desktop pool till see Windows Welcome): 5sec. --> till Complete login: 20 sec.

Login with 1 Appstack (select desktop pool till see Windows Welcome): 10sec. --> till Complete login: 28 sec.

Login with 2 Appstacks (select desktop pool till see Windows Welcome): 14sec. --> till Complete login: 33 sec.

Config: NOT Appstack attached directly on ESX host (ONE (see picture below) entries in vsphere when adding appvol HDD's)

Login with 1 Appstack (select desktop pool till see Windows Welcome): 10sec. --> till Complete login: 28 sec.

Login with 2 Appstacks (select desktop pool till see Windows Welcome): 10sec. --> till Complete login: 28sec.

Login with 4 Appstacks (select desktop pool till see Windows Welcome): 15sec. --> till Complete login: 33sec.

Kind Regards,

Ronny Anneveld

Ray_handels · ‎07-16-2015

Hey Ronny,

It does sem to be a little bit quicker than what we are seeing but still.

My guess would be that the reconfigure action should be done within a few seconds and should not matter if you have 1,2 or 10 appstacks because (not quite sure though) you should only change the VMX file and add the disks to this file.

Anyone from Appvolumes able to shed some light on the matter?? Even if this is what it should be it would still like to know.

But as said, strange thing is that we did not see this issue when using VSphere 5.1. Started popping up at 6.0.

sappomannoz · ‎07-22-2015

Hello,

it seems that removing the SATA controller and CD Drive speeds up the process.

anvr · ‎08-05-2015

Hello Sappomannoz,

Also try that and see little time difference, a few seconds.

Remember: If remove the cdrom drive, VMware tools upgrade is not possible.

Thanks for sharing.

Grtz.

Ronny.

sappomannoz · ‎08-05-2015

Hello,

you could remove che CDROM only in the snapshot you use for Recomposing. Also using VM Version 10 w/o sata gives a little login speed advantage

Regards

Cristiano

All

Logon times