Inconsistent and slow logins with any version of Appvolumes

[alienjoker]

‌Hey everyone,

We were running Appvolumes 2.10 and logins were 30+ seconds depending on the number of stacks assigned to a user. In some cases (Visio as an Appstack), logon times would shoot to in excess of a minute. We then upgraded to 2.11 as part of a Horizon 7 rollout (with vSphere 6 U2) and the logon times increased! Ouch! All areas of the build (the core is very vanilla) were reviewed alongside the hosts, storage, network and DB, but with no obvious problem areas. Each time this was raised with VMware, it was acknowledged that certain parameters that were applicable in 2.10 were no longer acknowledged in 2.11 and as there were product limitations for 2.11,  wait until 2.12 and there will be vast improvements!

Well, like others in the forum, during testing of Appvolumes 2.12, we are still seeing yet further slow down of logins!

We managed to improve the speed by dropping SSL, (setting to use port 80 from agent to manager), but the overall result is that logins are no better than where we stood before.

Interesting and unsurprisingly, stopping the svservice (AppVolumes) brings us back to circa 15 sec logins. However, just running the service even with no user stacks assigned adds about 10seconds to a typical logon so there seems to be an effective heavy penalty for it to merely check for user assignments, let alone attaching anything.

Im going to start investigating hardcoding requests to specific domain controllers in preference to using the domain fqdn in the configuration to see if that changes anything too. Will report back.

If anyone else has any similar experience or problems, please let me know as for us, 2.12 was considered to be the last roll of the dice for Appvolumes in preference to a rivals offering that seems capable of cutting our current logon times in half which for a userbase of 1000 multiplied by 15 seconds is the equivalent of 250minutes of lost productivity each time all users log on!

Thanks

Andrew

[pchapman]

I have seen the same on a recent deployment of 2.11 and upgraded to 2.12.  I too did not have any issues with prior versions.  This environment is using a writable as well.  Login times are well over a minute in some cases.

[Lakshman]

If you are using 2.12, you may conside asynchronous mounting to improve login time.

Enabling asynchronous mounting in App Volumes 2.12 (2147985) | VMware KB

[Ray_handels]

Hey Lakshman,

I might be misjudging this but Async mounting is still tech preview. I received a message from GSS that it is not supported officially.

That being said, when using a writable it still needs to wait for the writable to be attached, it will still need to wait for that.

What we see as baseline login times with a writable only is about 25 to 30 seconds. Every added appstack adds about 2 to 4 seconds on the logon time.

I would suggest trying to remove preference mode policies (if any) and create printers after Appvolumes is done attaching appstacks (could we please have either a log message or a reg key when Appvolumes is done processing?).

Also, are you using any profile management tool? And what virusscanner are you using? It could be that during attachment of the disks they are being scanned what could cause slow logon times.

And last but not least, is the machine using 100% of it's CPU during logon? We have seen this happening when using profile management other than UEM and Appvolumes as they are figthing for resources during logon (both filter drivers).

[Lakshman]

Hi Ray,

Yes, you are right. Async mounting is a Tech preview feature as mentioned in the release notes of 2.12.

However, i have seen that it improves login time for couple of customers who are not using writable volumes.

[Erossman]

Hi Andrew,

I saw the same behavior in the infrastructure of my clients.

Every AppVolumes version was not a really improvment because new issues appeared.

We use Win7x64 with mandatory profiles, UEM, appvol 2.11 and have login times between 50sec-120sec.

If we tried some of the parameters (vmware support told us to do this) in the appvol registry we saw that not all appstacks were intialized in the OS and could see the cvapps drives in the windows explorer.

I am afraid to upgrade to appvol 2.12. because vmware improved the logon times with the async mounting. It also seems that this behavior is a default!

User can see already the desktop but not all appstacks are finished with initializing. That's a no go!

You can find in the vmware forum some other people who get this issue, too.

Regards,

VM-Master

[alsmk2]

AV2.12 is a vast improvement over 2.11, which was sub-par. Logon times are faster, and it's quite rare to see applications taking long to appear in the desktop - that's without the async modification mentioned above.

What I noticed with 2.12 is that if you modify the registry to put the usual entries in that helped performance in previous version, it actually worsens performance. However, an out of the box agent install with no registry modifications works extremely well.

[Ray_handels]

We did a deep dive into why logon is slow and foudn out some interesting results.

@Andrew. Just for my reference as well Could you look into the svservice.log file to see if any of these 3 things are the case in your enviornment?

And as a good reference. We managed to get logintimes with a writable only (no appstack) within 17 seconds.

1. User policies. What we see happening is when we apply preference mode policies (and mostly preference mode) logon is delayed with about 5 to 7 seconds depending on the crap we set in there .

2. Reconfigure of the machine takes a long time. And this is the thing we see happening most.

What should happen is AV Agent asks manager for appstacks --> AV Manager ask VCenter to reconfigure --> Vcenter tells manager disks are there --> AV Manager tells AV Agent to proceed with logon. We see an extremeley large difference ranging from 2 seconds to about 30 seconds in this proces. And the reconfigure bug is not on the ESX host as we have the U2 installed. The reconfigure by VCenter is ebing done within seconds but in logging we see the manager apparently waiting for vcenter for over 15 to 20 seconds.

You can see this in the logging by looking at these lines. You see the 9 second difference inthere? This is the timeframe the above steps take place. This can range from 2 seconds to more than 30 seconds.

[2017-02-24 12:07:46.341 UTC] [svservice:P920:T3008] User login URL: /user-login?name <a bunch of more crap about who you are>

[2017-02-24 12:07:46.341 UTC] [svservice:P920:T3008] [0] Connecting to APPVOL_MANAGER URL:443 using HTTPS (attempt 1)

[2017-02-24 12:07:55.434 UTC] [svservice:P920:T3008] WinHttpSendRequestWithSSLCertValidation: SSL Certificate validation succeeded.

[2017-02-24 12:07:55.434 UTC] [svservice:P920:T3008] HttpReadAllAvailableData: Error 0 in WinHttpQueryDataAvailable: dwSize 0

3. Last but not least we are using a bunch of older appstacks. Some appstacks seem to have an issue with executing the startup.bat. If you look at the svservice.log file you can see a hiatus of about 10 seconds that the agent is waiting for the startup.bat.

Do you happen to see any of these??

[Gagan201110141]

vmwareappvol - Pastebin.com

Check out my slow log in times I did change my server ip to My server and we are using port 443 are people finding port 80 is faster or better to use?

[TDJB3]

I'll throw my hat into the ring.  We are having the same problems.

[Ray_handels]

If you guys do see slow logons could you try and post the parts where the svservice.log of the agent has "holes"  in it where a process seems to stall for multiple seconds? I'm not that eager to click on links that are not referring to the VMware site itself, i'd prefer to see the logs (with the second hiatus in it) or a screenshot .

[tschuegy]

Hi Ray

Can you take a look at my log? https://communities.vmware.com/thread/557946

Thx

Tschuegy

[Ray_handels]

Hey Tschuegy,

I did see that log but to be honest it seems quite legit as it is only 1 second timeframe delay.

We actually see a gap of over 15 seconds when executing the startup.bat

[2017-02-24 07:59:24.497 UTC] [svservice:P916:T4152] [0] Connecting to SERVERNAME:443 using HTTPS (attempt 1)

[2017-02-24 07:59:41.877 UTC] [svservice:P916:T4152] WinHttpSendRequestWithSSLCertValidation: SSL Certificate validation succeeded.

This one seems to be resolved by disabling certificatecheck. Change the EnforceSSLCertificateValidation value to 0. After we changed this in the golden image we see this timeframe consistenly going to about 3 to 5 seconds, which it should be.

The other issue we are still looking at it. is below where you see it waiting for about 10 seconds to start shellstart.bat. These 10 seconds are added to the actual logintime. Strange thing is that we don't see this happening with all appstacks.

[2017-03-07 09:20:01.129 UTC] [svservice:P912:T2668] RunExecutableAsUser: Path "\SnapVolumesTemp\MountPoints\{ID}\shellstart.bat"

CreateProcessWithTokenAndEnvBlockW() standard user or UAC turned off, continue...

[2017-03-07 09:20:01.135 UTC] [svservice:P912:T2668] Successfully launched (elevated privileges): \SnapVolumesTemp\MountPoints\{ID}\shellstart.bat (wait -1 ms), pid=2460 tid=3756

[2017-03-07 09:20:11.267 UTC] [svservice:P912:T2668] Finished waiting for "\SnapVolumesTemp\MountPoints\{ID}\shellstart.bat": CreationFlag 0x08000420, WaitStatus 0x00000000, ExitCode 0 (0x00)

[TDJB3]

Ray_handels,

I attached the svservice log file.  I highlighted a few things.  You will see one item with a gap of about 30 seconds.

[tschuegy]

Thank you TDJB3,

I think the product it selfe are very good, but it is toooooooo buggy. We have stopped the implementation for the moment. In future releases we will take another try to implement appvolumes.

Thank you all,

Tschuegy

[Ray_handels]

Hey TDJ,

This seems to be one of the issues we are seeing as wel. What happens in this timeframe is that the VDI is being reconfigured and the appstacks and the writable is being atttached. This should normally only take about 5 seconds max and not 17 seconds that you are seeing now.

If you look at your VCenter do you see how long it takes to actually reconfigure the machine? This should normally be done within 2 seconds. Do you have the U2 for ESX6? Or still running vanilla 6? Or another version maybe?

The resetting order and the OnStartShell is something we see as well. We are still working on this with support because it seems as if this only happens with a specific subset of appstacks when we look at our enviornment. I will keep you posted on progress, the good thing is we are not the only ones as it seems .

Did you open a ticket with VMWare?? And what do they tell you there?

[TDJB3]

Ray,

We are using vCenter Server 6.0 Update 2 Server Appliance Build 3634794.

I deleted a machine and once the task was completed, it took about 4.5 minutes to finish configuring the machine.

We do not have a ticket open with VMware.

[Gagan201110141]

I have had an open ticket with VMware and sent over my logs it's been 7 days and they can't figure it out just saying

I'm not very happy here with Windows 10 and app Vol

It's clear others are having issues so they should take note and fix the issue.

Hopefully next patch just wish they would say something

[Ray_handels]

Hey TDJ,

I didn't mean that. When you log in the manager sends a request to VCenter (or the ESX host depending on how you set things up) to add the appstacks. With the 6.0 Vanilla version of ESX it took up to 3 seconds per appstack to reconfigure. If you had 5 appstacks it could sometimes take up to 20 seconds to just reconfigure the machine. This issue has been fixed in the U2 version of ESX and you should see the reconfigure in the tasks screen of VCenter. This action (the reconfigure) should take up to 2 seconds.

I also see (although I have been told this couldn't be the case) that having the EnforeceSSLCertificateValidation set to 1 seems to cause that issue as well. You could try and set it to 0. The reconfigure of the machine (the 17 seconds you see in the logfile) should be about 5 seconds max depending on the amount of reconfigures your vcenter needs to execute.

Gagan, we are testing with W10 as well but I don't see very strange behaviour other than what we are used to in Windows 7. Logon times in W10 are slower than W7 with or without Appvolumes. I would suggest trying to find "holes" in the svservice.log file to see what is taking so long if you do have slow logon times. And I do agree with you that support (or VMware in general) could be a little bit more outspoken about pending issues, bugs or what they are trying to do to fix these things. The feeling I get is that they are really trying to do their best but communication lacks from time to time for whatever reason.

[JHT_Seattle]

Hey Ray -

I ran into a problem with an older stack of mine this last week and ended up resolving it by mounting an "update" of the vmdk to a VM without the appvol agent installed and copying files from the latest template into the screwy app stack.  Long story short, and to tie it to this thread, it also noticeably sped up mount/logon.

I remember asking Jason Marshall a long time ago for a true "upgrade" function in the GUI to insert these newer files into existing stacks, when I was thinking of versioning for stacks being integrated.  I could swear he said that was something they were working on, but I never saw it materialize.

Unfortunately, it's not possible (so far as I know) to see easily what version of a template was used for each stack.  I only see what agent version was used.

Just throwing this out there, since in an earlier reply you noted that you have several older stacks.  With 2.12.1 just around the corner, though, I'm going to wait until that template is available to do anything further (since it includes the virtual printer fix).