VMware Horizon Community
Ray_handels
Virtuoso
Virtuoso

Slow logon and attachment of Appstacks in 2.11

Hey Guys,

We are test driving Appvolumes 2.11 because we have some minor issues with the 2.9 version we are using now.

Apparently everything does seem to work when logging in but it takes quite some time to be able to log in.

When looking into the svservice.log file is see a bunch of these error messages as stated below. I am logging in with a user that has 1 writable volume and 5 appstacks. Normally this shouldn't be an issue but when looking at the logging this Blocking sometimes adds up to about 20 seconds which is all added into the logon time.

I tried adding the VolWaitTimeout=5 reg key but then my writable volume isn't even attached so I don't have any user settings and I normally get a reboot the desktop message.

[2016-07-05 11:29:36.324 UTC] [svservice:P972:T1176] Blocking user logon while waiting for 6 new volumes (0 processed, waited 1 second(s) so far, max wait of 180)

[2016-07-05 11:29:37.324 UTC] [svservice:P972:T1176] Blocking user logon while waiting for 6 new volumes (0 processed, waited 2 second(s) so far, max wait of 180)

[2016-07-05 11:29:38.324 UTC] [svservice:P972:T1176] Blocking user logon while waiting for 6 new volumes (0 processed, waited 3 second(s) so far, max wait of 180)

[2016-07-05 11:29:39.324 UTC] [svservice:P972:T1176] Blocking user logon while waiting for 6 new volumes (0 processed, waited 4 second(s) so far, max wait of 180)

[2016-07-05 11:29:40.324 UTC] [svservice:P972:T1176] Blocking user logon while waiting for 6 new volumes (0 processed, waited 5 second(s) so far, max wait of 180)

[2016-07-05 11:29:41.324 UTC] [svservice:P972:T1176] Blocking user logon while waiting for 6 new volumes (0 processed, waited 6 second(s) so far, max wait of 180)

[2016-07-05 11:29:42.324 UTC] [svservice:P972:T1176] Blocking user logon while waiting for 6 new volumes (0 processed, waited 7 second(s) so far, max wait of 180)

[2016-07-05 11:29:43.324 UTC] [svservice:P972:T1176] Blocking user logon while waiting for 6 new volumes (0 processed, waited 8 second(s) so far, max wait of 180)

I would love to see other peoples experiences with this. Any extra info would be very appreciated..

Ray.

0 Kudos
13 Replies
jahos_
Enthusiast
Enthusiast

I had the same issue. Support told me to add the volwaittimeout reg key and set it to 2. This solved it (well at least the slow logon, not sure if the root cause is resolved)

0 Kudos
Ray_handels
Virtuoso
Virtuoso

Are you also using the Appvolumes 2.11 version? The issue is that when I set this key (which indeed solves the blocked login issue) that my writable volume (which we are using) is not being applied correctly.

In the 2.9 (or non writable volume configuration) this could be fixed by using the VolDelayLoadTime=0 regkey so it would first attach the writable volume, then proceed to login and the attach the appstacks later on.

If I do the exact same thing in 2.11 my writable volume settings are not being applied, althoug the writable volume is being attached. My guess is that it needs to block the logon until the writable volume (or all volumes for that matter) are attached before it can proceed to logon. Otherwise Windows will create a local profile for me on the VDI and the writable volume then overwrites this during logon.

And what you will see happening know is that appstacks are being attached at a later timeframe. It could well be that an application is not available after the user logs in because it still needs to attach the appstack after login.

0 Kudos
jahos_
Enthusiast
Enthusiast

‌yes, also 2.11.

Altough I can understand this for writable volumes, this should not occur when NOT using writable volumes.

0 Kudos
Smoke14
Hot Shot
Hot Shot

I'm troubleshooting the same issue with AV 2.11.

We are not using WV at all and it seems that we see the logon slowness after attaching the second AppStack and beyond. Here is the times I'm currently trying reduce back to at least 40 sec logon.

Windows 10 (Avg Logon Times)

  • Login with no AppStack - 30 sec
  • Login with 1 AppStack - 50 sec
  • Login with 2 or more AppStack - 1:16 min

I made the following 'Volume behavior parameter' changes and it seem to help very little.

  • VolWaitTimeout = 5
  • VolDelayLoadTime = 5
  • RebootAfterDetach = 1 (This entry is for another issue I'm testing, just wanted to show all changes)

Windows 10 (Avg Logon Times - With Changes)

  • Login with no AppStack - 30 sec
  • Login with 1 AppStack - 50 sec
  • Login with 2 or more AppStack - 1 min

These are average timings but they defiantly show a patter. We are also using UEM 9.0, I assume this will have a little to do with logon timing, because of the GPO's being applied and folder redirection. But nothing that should cause a big hit in logon times.

Any help or suggestions would be appreciated, if not, I will be placing a SR in the coming days for this problem and keep everyone updated with our findings.

Mike A.

Mike_A
0 Kudos
Ray_handels
Virtuoso
Virtuoso

Hey Mike,

Do you also see the blocking user logon errors in the svservice.log?

It seems that attaching the appstacks in 2.11 takes a lot longer than it did in version 2.9. Also, using the VolWaitTimeout = 5 and VolDelayLoadTime = 5 doesn't seem to do the trick anymore because our writable volume isn't being applied at all anymore or at least the settings aren't.

We are in the process of trying to get this fixed with support. If you have the same issues please open an SR and if so I can provide you with mine.

0 Kudos
DLINK
Contributor
Contributor

i filed a ticket as well this morning

0 Kudos
Smoke14
Hot Shot
Hot Shot

Ray,

Sent you and DLINK a private message with my SR# and asking you all to reply with yours, so I can reference them in my SR for support to track.

Thx,

Mike_A

Mike_A
0 Kudos
hockeyguyin714
VMware Employee
VMware Employee

Are you using mixed 2.11.0 and older versions of AppStacks?

Does it occur without the 2.11.0 AppStacks?

0 Kudos
Ray_handels
Virtuoso
Virtuoso

Yes we are mixing older version with the 2.11 agent (as far back as 2.6 and 2.9) but we also tried with only a writable volume that was created withe the 2.11 template and also saw that the login was blocked for 4 to 5 seconds. I will be trying to create a few new appstacks (or update the old ones) to version 2.11 but was told that this is not necessary (good sources Smiley Happy)  so this was something that i didn;t try yet. Also because we have about 90 appstacks and updating them all takes some time.

0 Kudos
Ray_handels
Virtuoso
Virtuoso

Update.

I've treid with a 2.11 Manager, 2.11 Agent, 2.11 writable volume and a 2.11 newly created very simple appstack (just 3 easy applications) and still I see the exact same issue. Here's a small capture of the svservice log on the machine. And eventually it adds up to 6 or 7 seconds that it says Blocking user logon. The time that it has to wait also differce quite a bit.

The settings "Wait for first volume only is 1" (for as far as I know) should mean that I only need to wait for the writable volume before it should proceed with the login process, this is clearly not the case. even then so. Waiting for 5 to 10 seconds to attach a newly created writable volume and an appstack with close to none information in it is way to long. Even more so because this has never been an issue with the 2.9 version we are using now.

[2016-07-11 08:45:46.035 UTC] [svservice:P964:T2804] SvdSetReorderCounter: set to 2

[2016-07-11 08:45:46.035 UTC] [svservice:P964:T2804] Activate filtering (called by ReadOutVolsFromString)

[2016-07-11 08:45:46.035 UTC] [svservice:P964:T2804] LogonMount: agent:0 manager:2 volume(s) to attach

[2016-07-11 08:45:46.035 UTC] [svservice:P964:T2804] WaitVolumesLoading: waiting for 2 total volume(s), 0 processed, max wait 180

[2016-07-11 08:45:46.035 UTC] [svservice:P964:T2804] WaitVolumesLoading: Wait for first volume only is 1

[2016-07-11 08:45:46.036 UTC] [svservice:P964:T1108] Preload volume event (startup): "\Device\HarddiskVolume2" GUID {7e6c2774-df6d-11e4-bc49-806e6f6e6963} Hive  (0 logged in, SystemVolume 1, VolumeType 0)

[2016-07-11 08:45:46.036 UTC] [svservice:P964:T1108] Sending reply to SVCMD_ID_NEW_VOLUME_PRE (Message 1, Size 24)

[2016-07-11 08:45:47.035 UTC] [svservice:P964:T2804] Blocking user logon while waiting for 2 new volumes (0 processed, waited 1 second(s) so far, max wait of 180)

[2016-07-11 08:45:48.035 UTC] [svservice:P964:T2804] Blocking user logon while waiting for 2 new volumes (0 processed, waited 2 second(s) so far, max wait of 180)

[2016-07-11 08:45:49.035 UTC] [svservice:P964:T2804] Blocking user logon while waiting for 2 new volumes (0 processed, waited 3 second(s) so far, max wait of 180)

[2016-07-11 08:45:49.820 UTC] [svservice:P964:T1108] Preload volume event (startup): "\Device\HarddiskVolume4" GUID {9b0f8f3a-e37b-11e4-8da5-005056b24b1a} Hive  (0 logged in, SystemVolume 0, VolumeType 0)

[2016-07-11 08:45:49.823 UTC] [svservice:P964:T1108] Worker: read meta ID:("{e95e1569-7f20-4baa-a29f-9ccc7d34ef0e}") success!

0 Kudos
Smoke14
Hot Shot
Hot Shot

I'm not getting the 'Blocking user logon while...' entries in my logs. But I'm not using WV either.

I did notice you have the default of 180 to wait. you need to make the AV parameter changes in your master image to see is delaying a shorter time works for you.

Mike_A
0 Kudos
Ray_handels
Virtuoso
Virtuoso

Hey Smoke.

As said in a post earlier in this thread. If I set the VolWaitTimeout registry key my writable volume isn't being applied correctly.

I've created a new appstack with 2.11 Agent and assigned this as the only appstack to the machine and I still see the blocking user logon message in my svservice.log file. I've disabled my writable volume and when looking at the logging this is indeed the only appstack being applied.

I am very interested to find out why it produces this message even though I am not using a writable volume that is being assigned to my account. Why is it blocking login if I don't have a writable volume. And what could cause this 5 second hole during attachment of the appstack. I've looked at all kinds of logs files but can't seem to explain it in any way.

Could it be that you have ESXi 6.0 vanilla or with U1 (not U2) and that reconfigure of the machine takes quite some time?

0 Kudos
bclyde
Enthusiast
Enthusiast

Hi,

If you create new Appstacks for 2.11, the default policy includes a line:

 

reverse_replication….****

 

This line is meant to improve performance for certain applications which enumerate heavy keys in the registry.

 

In some cases  it would cause very long login times, if you encounter this for new appstacks, just remove this line from the policy.

Give that a go, see if it helps mate.

Barry.

 

0 Kudos