Caution: FSLogix 2009 (2.9.7621.30127) profiles won’t logoff completely

At three customer sites I created test machine catalogs with FSLogix 2009, and all of them had the same issue, that FSLogix profiles won’t logoff completely at the end of the day.

Hanging profiles (2)

Update January 11, 2021: I was informed about a better solution via Twitter, and updated the Blog post accordingly.

The Problem

During my personal tests with FSLogix 2009 (2.9.7621.30127) I discovered that the profiles won’t logoff completely at the end of the day. See the following screenshots.

You can clearly see, that despite there are no active or disconnected user sessions, some of the VHDX disks are still mounted, but more important the folders from C:\users\ won’t vanish.

This makes a second login impossible on the same VDA.

The situation

At my Citrix Machine creation services (MCS) customers, I never update machine catalogs, I always replace them with fresh Golden master images installed from scratch via Microsoft Deployment Toolkit (MDT). So all tests were performed on a freshly installed machine catalog. No in-place upgrade of the FSLogix apps or the Citrix VDA. This is the affected test environment:

  • Windows Server 2016 de-DE
    (
    December 8, 2020—KB4593226 (OS Build 14393.4104))
  • Citrix VDA 1912 CU2 via MCS
  • FSLogix 2009 (2.9.7621.30127)
    (Single SMB share, no Cloud Cache)

Every second day, the test users were unable to login. A reboot could solve the problem temporary.

I wasn’t able to find anything meaningful in the FSLogix logs, but I post them non the less at the end of the blog post, so someone with the same issue might be able to find this blog post through his favorite search engine.

The (old) solution

The solution to my problem, after lots of different tests, was to downgrade to FSLogix 2004 (2.9.7349.30108) and all problems were instantly gone. The current test (and soon to be productive) environments for all my customers look like this now:

  • Windows Server 2016 de-DE
    (December 8, 2020—KB4593226 (OS Build 14393.4104))
  • Citrix VDA 1912 CU2 via MCS
  • FSLogix 2004 (2.9.7349.30108)
    (Single SMB share, no Cloud Cache)

The better solution

This paragraph was added on 11.01.2021

Soon after I published this blog post, Fredrik Endresen contacted my on Twitter, with the following statement:

He encountered the same problems as we did, and during his troubleshooting he discovered an undocumented FSLogix change in version 2009 (2.9.7621.30127). According to him, FSLogix uses the SID of the local include/exclude groups now, instead of the name. As I manage those groups via Group Policy Preferences (GPP) and choose the mode replace instead of update, these groups get re-created during the Group Policy background refresh, which changes the SID, resulting in the issues described above.

Now the real solution would be, to double check how you manage the local FSLogix groups. If you don’t manage them via GPP, there is a great change you belong to the group of people, not affected by this problem.
Now I will test this theory during the next Citrix MCS Master Image tests, set my GPP to update instead of replace, and also as mentioned in the comments and in the World of EUC Slack, the new registry value CleanupInvalidSessions.

The FSlogix logs

FSL1.txt

[07:11:34.447][tid:00000ea0.00000ea4][INFO]            Max retries reached.  Giving up re-attach attempts.
[07:11:34.447][tid:00000ea0.00000ea4][ERROR:c03a000e]  OpenVirtualDisk (The virtual disk chain is damaged. The identifier of the parent virtual disk and the identifier of the differing disk conflict.)
[07:11:34.447][tid:00000ea0.00000ea4][INFO]           ===== End Session: Volume re-attach
[07:11:34.447][tid:00000ea0.00000ea4][INFO]           Configuration setting not found: SOFTWARE\FSLogix\Profiles\ReAttachRetryCount.  Using default: 60
[07:11:34.447][tid:00000ea0.00000ea4][INFO]           Configuration setting not found: SOFTWARE\FSLogix\Profiles\ReAttachIntervalSeconds.  Using default: 10
[07:11:34.447][tid:00000ea0.00000ea4][INFO]           ===== Begin Session: Volume re-attach
[07:11:34.447][tid:00000ea0.00000ea4][INFO]            Attempting re-attach of volume: \\?\Volume{f9af2c8e-7617-4e92-a2a9-71d301a2e7b6}\ for SID: S-1-5-21-3307134969-3200570010-XXX-2393
[07:11:34.447][tid:00000ea0.00000ea4][INFO]            Configuration setting not found: SOFTWARE\FSLogix\Profiles\LogonSyncMutexTimeout.  Using default: 60000
[07:11:34.447][tid:00000ea0.00000ea4][INFO]            Acquired reattach virtual disk lock for user S-1-5-21-3307134969-3200570010-XXX-2393 (Elapsed time: 0)
[07:11:34.447][tid:00000ea0.00000ea4][WARN: 00000002]  Error querying VHDReAttachFilePath (The system can not find the stated file.)
[07:11:34.447][tid:00000ea0.00000ea4][INFO]            VHDPath: C:\windows\TEMP\S-1-5-21-3307134969-3200570010-XXX-2393_RO.VHDX
[07:11:34.447][tid:00000ea0.00000ea4][ERROR:00000002]  WTSQueryUserToken (The system can not find the stated file.)
[07:11:34.447][tid:00000ea0.00000ea4][INFO]            We are supposed to re-attach as the user, but we're unable to.  Trying as computer object.
[07:11:34.447][tid:00000ea0.00000ea4][INFO]            Attempting re-attach as the computer
[07:11:34.447][tid:00000ea0.00000ea4][INFO]            Retry Count: 60  Retry Interval (seconds): 10
[07:11:34.462][tid:00000ea0.00000ea4][INFO]            Unsuccessful re-attach attempt.  Retry in 10 seconds.
[07:11:44.478][tid:00000ea0.00000ea4][INFO]            Retrying re-attach (1 of 60)
[07:11:44.478][tid:00000ea0.00000ea4][INFO]            Unsuccessful re-attach attempt.  Retry in 10 seconds.
[07:11:54.494][tid:00000ea0.00000ea4][INFO]            Retrying re-attach (2 of 60)
[07:11:54.494][tid:00000ea0.00000ea4][INFO]            Unsuccessful re-attach attempt.  Retry in 10 seconds.
[07:12:04.510][tid:00000ea0.00000ea4][INFO]            Retrying re-attach (3 of 60)
[07:12:04.510][tid:00000ea0.00000ea4][INFO]            Unsuccessful re-attach attempt.  Retry in 10 seconds.
[07:12:14.526][tid:00000ea0.00000ea4][INFO]            Retrying re-attach (4 of 60)
[07:12:14.526][tid:00000ea0.00000ea4][INFO]            Unsuccessful re-attach attempt.  Retry in 10 seconds.
[07:12:24.541][tid:00000ea0.00000ea4][INFO]            Retrying re-attach (5 of 60)
[07:12:24.541][tid:00000ea0.00000ea4][INFO]            Unsuccessful re-attach attempt.  Retry in 10 seconds.
[07:12:34.557][tid:00000ea0.00000ea4][INFO]            Retrying re-attach (6 of 60)
[07:12:34.557][tid:00000ea0.00000ea4][INFO]            Unsuccessful re-attach attempt.  Retry in 10 seconds.

FSL2.txt

[07:53:04.861][tid:00000ea0.00002c40][INFO]              Removal of folder redirection complete
[07:53:04.917][tid:00000ea0.00002c40][INFO]              Export profile registry info complete
[07:53:04.917][tid:00000ea0.00002c40][INFO]              Configuration setting not found: SOFTWARE\FSLogix\Profiles\GroupPolicyState.  Using default: 0
[07:53:04.918][tid:00000ea0.00002c40][INFO]              Removed redirection from C:\Users\xentest
[07:53:04.918][tid:00000ea0.00002c40][ERROR:00000091]    RemoveDirectory failure C:\Users\xentest (Das Verzeichnis ist nicht leer.)
[07:53:04.918][tid:00000ea0.00002c40][INFO]              Configuration setting not found: SOFTWARE\FSLogix\Profiles\ControlTileService.  Using default: 0
[07:53:04.918][tid:00000ea0.00002c40][INFO]              Opening RW diff disk: \\hartfs01.domain.local\profiles_ctx$\xentest_S-1-5-21-3307134969-3200570010-XXX-4611\RW.VHDX
[07:53:05.051][tid:00000ea0.00002c40][INFO]              Detached vhd(x)
[07:53:05.051][tid:00000ea0.00002c40][INFO]              VHD(x) Detach request returning after 141 milliseconds
[07:53:05.052][tid:00000ea0.00002c40][INFO]              Configuration Read (DWORD): SOFTWARE\FSLogix\Profiles\KeepLocalDir.  Data: 0
[07:53:05.052][tid:00000ea0.00002c40][INFO]              Directory removal queued: C:\Users\local_xentest1
[07:53:05.052][tid:00000ea0.00002c40][INFO]              Device cleanup queued
[07:53:05.052][tid:00000ea0.00002c40][INFO]              Configuration setting not found: SOFTWARE\FSLogix\Profiles\DeleteProfileOnLogoff.  Using default: 1
[07:53:05.052][tid:00000ea0.00002c40][INFO]              Configuration setting not found: SOFTWARE\FSLogix\Profiles\DeleteProfileTimeout.  Using default: 30000
[07:53:05.052][tid:00000ea0.00002040][INFO]           ===== Begin Session:    Remove Local Directory
[07:53:05.053][tid:00000ea0.000022e0][INFO]               Deleting profile on logoff
[07:53:05.153][tid:00000ea0.00000bf8][INFO]           ===== Begin Session:     Remove Unused Device Information
[07:53:05.176][tid:00000ea0.00002040][INFO]                Successfully removed C:\Users\local_xentest1
[07:53:05.183][tid:00000ea0.00000bf8][INFO]                Devices removed: 2. Errors: 0
[07:53:05.183][tid:00000ea0.00000bf8][INFO]           ===== End Session:     Remove Unused Device Information
[07:53:05.245][tid:00000ea0.00002040][INFO]               Successfully removed C:\Users\local_xentest
[07:53:05.245][tid:00000ea0.00002040][INFO]           ===== End Session:    Remove Local Directory
[07:53:05.515][tid:00000ea0.000022e0][ERROR:00000490]    Failed to Remove Profile for sid S-1-5-21-3307134969-3200570010-XXX-4611 (Element not found.)
[07:53:05.515][tid:00000ea0.000022e0][ERROR:00000002]    Error removing profile key for sid S-1-5-21-3307134969-3200570010-XXX-4611 (The system can not find the stated file.)
[07:53:05.516][tid:00000ea0.00002c40][INFO]              Root VHD: \\hartfs01.domain.local\profiles_ctx$\xentest_S-1-5-21-3307134969-3200570010-XXX-4611\Profile_xentest.VHDX
[07:53:05.516][tid:00000ea0.00002c40][INFO]              RW Diff disk: \\hartfs01.domain.local\profiles_ctx$\xentest_S-1-5-21-3307134969-3200570010-XXX-4611\RW.VHDX
[07:53:05.516][tid:00000ea0.00002c40][INFO]              RO Diff disk: C:\windows\TEMP\S-1-5-21-3307134969-3200570010-XXX-4611_RO.VHDX
[07:53:05.517][tid:00000ea0.00002c40][INFO]              Attempting merge of diff disk: \\hartfs01.domain.local\profiles_ctx$\xentest_S-1-5-21-3307134969-3200570010-XXX-4611\RW.VHDX
[07:53:05.535][tid:00000ea0.00002c40][INFO]              Opened diff disk.  Attempting merge.
[07:53:05.613][tid:00000ea0.00002c40][INFO]              Merge successful
[07:53:05.613][tid:00000ea0.00002c40][INFO]              Merged RW diff: \\hartfs01.domain.local\profiles_ctx$\xentest_S-1-5-21-3307134969-3200570010-XXX-4611\RW.VHDX
[07:53:05.615][tid:00000ea0.00002c40][INFO]              UnloadProfile successful.  User: xentest. SID: S-1-5-21-3307134969-3200570010-XXX-4611.
[07:53:05.615][tid:00000ea0.00002c40][INFO]              unloadProfile time: 1015 milliseconds

FSL3.txt

[07:57:45.390][tid:00000ea0.00000ea4][INFO]            Unsuccessful re-attach attempt.  Retry in 10 seconds.
[07:57:55.390][tid:00000ea0.00000ea4][INFO]            Retrying re-attach (57 of 60)
[07:57:55.398][tid:00000ea0.00000ea4][INFO]            Unsuccessful re-attach attempt.  Retry in 10 seconds.
[07:58:05.398][tid:00000ea0.00000ea4][INFO]            Retrying re-attach (58 of 60)
[07:58:05.406][tid:00000ea0.00000ea4][INFO]            Unsuccessful re-attach attempt.  Retry in 10 seconds.
[07:58:15.407][tid:00000ea0.00000ea4][INFO]            Retrying re-attach (59 of 60)
[07:58:15.415][tid:00000ea0.00000ea4][INFO]            Max retries reached.  Giving up re-attach attempts.
[07:58:15.415][tid:00000ea0.00000ea4][ERROR:c03a000e]  OpenVirtualDisk (The virtual disk chain is damaged. The identifier of the parent virtual disk and the identifier of the differing disk conflict.)
[07:58:15.415][tid:00000ea0.00000ea4][INFO]           ===== End Session: Volume re-attach
[07:58:15.417][tid:00000ea0.00000ea4][INFO]           Configuration setting not found: SOFTWARE\FSLogix\Profiles\ReAttachRetryCount.  Using default: 60
[07:58:15.417][tid:00000ea0.00000ea4][INFO]           Configuration setting not found: SOFTWARE\FSLogix\Profiles\ReAttachIntervalSeconds.  Using default: 10
[07:58:15.417][tid:00000ea0.00000ea4][INFO]           ===== Begin Session: Volume re-attach
[07:58:15.417][tid:00000ea0.00000ea4][INFO]            Attempting re-attach of volume: \\?\Volume{f9af2c8e-7617-4e92-a2a9-71d301a2e7b6}\ for SID: S-1-5-21-3307134969-3200570010-XXX-2393
[07:58:15.417][tid:00000ea0.00000ea4][INFO]            Configuration setting not found: SOFTWARE\FSLogix\Profiles\LogonSyncMutexTimeout.  Using default: 60000
[07:58:15.417][tid:00000ea0.00000ea4][INFO]            Acquired reattach virtual disk lock for user S-1-5-21-3307134969-3200570010-XXX-2393 (Elapsed time: 0)
[07:58:15.417][tid:00000ea0.00000ea4][WARN: 00000002]  Error querying VHDReAttachFilePath (The system can not find the stated file.)
[07:58:15.417][tid:00000ea0.00000ea4][INFO]            VHDPath: C:\windows\TEMP\S-1-5-21-3307134969-3200570010-XXX-2393_RO.VHDX
[07:58:15.417][tid:00000ea0.00000ea4][ERROR:00000002]  WTSQueryUserToken (The system can not find the stated file.)
[07:58:15.417][tid:00000ea0.00000ea4][INFO]            We are supposed to re-attach as the user, but we're unable to.  Trying as computer object.
[07:58:15.417][tid:00000ea0.00000ea4][INFO]            Attempting re-attach as the computer
[07:58:15.417][tid:00000ea0.00000ea4][INFO]            Retry Count: 60  Retry Interval (seconds): 10
[07:58:15.428][tid:00000ea0.00000ea4][INFO]            Unsuccessful re-attach attempt.  Retry in 10 seconds.
[07:58:25.429][tid:00000ea0.00000ea4][INFO]            Retrying re-attach (1 of 60)
[07:58:25.437][tid:00000ea0.00000ea4][INFO]            Unsuccessful re-attach attempt.  Retry in 10 seconds.

Eventlog

Eventlog
Eventlog

Event1.txt

Driver installation failed. Result = 0x80070422 für devnode "STORAGE\VOLUME\{17941A03-3A00-11EB-91B8-806E6F6E6963}#0000000000010000".
Driver installation failed. Result = 0x80070422 für devnode "SCSI\DISK&VEN_VMWARE&PROD_VIRTUAL_DISK\5&22BE343F&0&000100".
Driver installation failed. Result = 0x80070422 für devnode "SCSI\DISK&VEN_VMWARE&PROD_VIRTUAL_DISK\5&22BE343F&0&000200".
Driver installation failed. Result = 0x80070422 für devnode "STORAGE\VOLUME\{17941A04-3A00-11EB-91B8-806E6F6E6963}#0000000000100000".
Driver installation failed. Result = 0x80070422 für devnode "TERMINPUT_BUS\UMB\2&2C22BCC9&0&SESSION2KEYBOARD0".
Driver installation failed. Result = 0x80070422 für devnode "TERMINPUT_BUS\UMB\2&2C22BCC9&0&SESSION2MOUSE0".
Driver installation failed. Result = 0x80070422 für devnode "STORAGE\VOLUME\{17941A03-3A00-11EB-91B8-806E6F6E6963}#0000000000010000".
Driver installation failed. Result = 0x80070422 für devnode "SCSI\DISK&VEN_VMWARE&PROD_VIRTUAL_DISK\5&22BE343F&0&000100".
Driver installation failed. Result = 0x80070422 für devnode "SCSI\DISK&VEN_VMWARE&PROD_VIRTUAL_DISK\5&22BE343F&0&000200".
Driver installation failed. Result = 0x80070422 für devnode "STORAGE\VOLUME\{17941A04-3A00-11EB-91B8-806E6F6E6963}#0000000000100000".
Driver installation failed. Result = 0x80070422 für devnode "TERMINPUT_BUS\UMB\2&2C22BCC9&0&SESSION2KEYBOARD0".
Driver installation failed. Result = 0x80070422 für devnode "TERMINPUT_BUS\UMB\2&2C22BCC9&0&SESSION2MOUSE0".
Driver installation failed. Result = 0x80070422 für devnode "SCSI\DISK&VEN_MSFT&PROD_VIRTUAL_DISK\2&1F4ADFFE&0&000003".
Driver installation failed. Result = 0x80070422 für devnode "SCSI\DISK&VEN_MSFT&PROD_VIRTUAL_DISK\2&1F4ADFFE&0&000004".
Driver installation failed. Result = 0x80070422 für devnode "SWD\MMDEVAPI\{3.0.0.00000004}.{61654801-7364-7465-2045-617270686F00}".
Driver installation failed. Result = 0x80070422 für devnode "SWD\MMDEVAPI\{3.0.1.00000003}.{6B694D02-6F72-6F66-6E20-284E56494400}".
Driver installation failed. Result = 0x80070422 für devnode "SWD\MMDEVAPI\{3.0.1.00000003}.{61654802-7364-7465-204D-6963726F7000}".
Driver installation failed. Result = 0x80070422 für devnode "SWD\MMDEVAPI\{3.0.0.00000003}.{75614C01-7374-7270-6563-686572202800}".
Driver installation failed. Result = 0x80070422 für devnode "SWD\MMDEVAPI\{3.0.0.00000003}.{65705301-6B61-7265-7320-284E56494400}".
Driver installation failed. Result = 0x80070422 für devnode "SWD\MMDEVAPI\{3.0.0.00000003}.{61654801-7364-7465-2045-617270686F00}".

 

Author: Marco

Marco is an IT-System administrator and IT-Consultant with 10+ years experience. He is specialized in the delivery of virtual Apps and Desktops with Citrix solutions. In 2017 he has been awarded Citrix Technology Advocate by Citrix for his community work (#CTA). His second core area is availability & performance monitoring with Zabbix, a leading open-source solution. His employer is the German IT-Company ANAXCO, which is developing a Transport Management Software (TMS) based on Microsoft Dynamics AX. More about Marco

9 thoughts on “Caution: FSLogix 2009 (2.9.7621.30127) profiles won’t logoff completely”

  1. Hi Marco,

    Have you seen this in the release notes
    CleanupInvalidSessions
    SET IN: Software\fslogix\apps\CleanupInvalidSessions

    Available in FSLogix release 2009 or later

    TypeDWORD

    Default Value 0

    At times a Windows Session may suffer an inelegant termination, in these cases FSLogix is not provided an appropriate event to trigger the dismount of the VHD(x) file for Profile Container and Office Container. By setting CleanupInvalidSessions to 1, additional FSLogix logic is triggered to make this scenario less likely. Setting CleanupInvalidSessions will cause the functionality to be utilized for both Profile Container and Office Container. KNOWN ISSUE: at this time CleanupInvalidSessions should not be used in conjunction with Cloud Cache when concurrent sessions (e.g utilizing ProfileType/VHDAccessMode) are in use.

  2. I’ve tried the CleanupInvalidSessions suggestion which didn’t work.
    This doesn’t seem to affect all of our setups.

  3. Hello Marco,

    I found your article in the hope of a solution.

    Unfortunately, the problem doesn’t really seem to have anything to do with the groups.
    We don’t distribute the groups with GPP and we have the problem.
    I really believe the issue has to do with the version of FSLogix.

    I’ve described the problem here. Link: https://docs.microsoft.com/en-us/answers/questions/229309/fslogix-unclean-logoff-causing-locked-files-until.html

    Unfortunately so far without success.

    Best regards
    Michael

  4. Interestingly we have the same issues with the 2004 v2.9.7349.30108 release. Probably ther’s something else causing this kind of behavior, maybe another Microsoft update on the OS side…

  5. Hi,
    I experience the same problems with the current fslogix release on Windows Virtual Desktop. Has anyone seen a solution for this ? I´ve also tried the CleanupInvalidSessions reg key, but it does not solve this issue at all. I´m kinda lost here and user profiles are all over the place right now.

    Thanks

    1. Hi,
      I have the same problem with the 2009 HF_01 with Cloud Cache.
      At the next logon the user have a black screen (unable to access in exclusive mode with the vhdx).
      Do you have news about this problem?

      Thanks

  6. Was facing this recently, solution was using GPOs to configure RDS inactive and idle disconnect times, we also applied the reg key for cleanupinvalidsessions with value to each SessionHost. Also had this script handy but didn’t implement it, did test it from cloudshell.
    GPO added to session hosts OU for sessions, I didn’t configure anything for active sessions and setup two hour time outs for idle and disconnected sessions to allow an hour or so for lunch.

    In the Group Policy Management Editor, navigate to Computer Configuration > Policies > Administrative Templates > Windows Components > Remote Desktop Services > Remote Desktop Session Host > Session Time Limits.

    Script to fix session hosts, run from azure portal using run as, if i was feeling fancy I would use a get-azvm in there and a parralell flag to do it at once, but only had a few session hosts to run it against, make this change on golden image if you can.
    $registryPath = “HKCU:\Software\fslogix\apps”

    $Name = “CleanupInvalidSesions”

    $value = “1”

    IF(!(Test-Path $registryPath))

    {

    New-Item -Path $registryPath -Force | Out-Null

    New-ItemProperty -Path $registryPath -Name $name -Value $value -PropertyType DWORD -Force | Out-Null}

    ELSE {

    New-ItemProperty -Path $registryPath -Name $name -Value $value -PropertyType DWORD -Force | Out-Null}

    (Get-ItemProperty -Path HKCU:\Software\fslogix\apps -Name CleanupInvalidSesions).CleanupInvalidSesions

Leave a Reply

Your email address will not be published. Required fields are marked *

This site uses Akismet to reduce spam. Learn how your comment data is processed.