none
Locked VHD(X) file, issues when logging in RRS feed

  • Question

  • Running into issues with a WVD environment consisting of 1 host pool and 2 Windows 10 Multi-Session host. Sometimes the users are unable to login, the FSLogix logs shows that the VHDX file is locked by another process (Error near the end). Only 5 users log on to a oversized host (64GB, 14vCPU, 256 Premium SSD). The sizing can't be the issue, but how do i determine which file/process is responsible for locking the VHDX? (the server was rebooted before the users started to login, so there were no disconnected sessions). Also, the latest FSLogix agent 1909 was installed on both servers.

     

    [09:01:18.407][tid:00000f34.00002bf8][INFO] ===== Begin Session: Logon
    [09:01:18.407][tid:00000f34.00002bf8][INFO] User: S-1-5-21-687924372-4293999746-2831884817-1299 (Testuser)
    [09:01:18.407][tid:00000f34.00002bf8][INFO] Acquiring mutex for user logon
    [09:01:18.408][tid:00000f34.00002bf8][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\LogonSyncMutexTimeout. Using default: 60000
    [09:01:18.408][tid:00000f34.00002bf8][INFO] Mutex acquired
    [09:01:18.408][tid:00000f34.00002bf8][INFO] ===== Begin Session: LoadProfile: Testuser
    [09:01:18.408][tid:00000f34.00002bf8][INFO] Configuration Read (DWORD): SOFTWARE\FSLogix\Profiles\Enabled. Data: 1
    [09:01:18.408][tid:00000f34.00002bf8][INFO] User: Testuser. SID: S-1-5-21-687924372-4293999746-2831884817-1299.
    [09:01:18.409][tid:00000f34.00002bf8][INFO] Include group SID: S-1-5-21-3446287254-2035122344-4217171115-1001
    [09:01:18.409][tid:00000f34.00002bf8][INFO] Exclude group SID: S-1-5-21-3446287254-2035122344-4217171115-1000
    [09:01:18.409][tid:00000f34.00002bf8][INFO] User is a member of the include group
    [09:01:18.409][tid:00000f34.00002bf8][INFO] Status set to 200: Setup in progress
    [09:01:18.409][tid:00000f34.00002bf8][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\RedirectType. Using default: 2
    [09:01:18.409][tid:00000f34.00002bf8][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\ConcurrentUserSessions. Using default: 1
    [09:01:18.410][tid:00000f34.00002bf8][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\VolumeWaitTimeMS. Using default: 20000
    [09:01:18.410][tid:00000f34.00002bf8][INFO] Configuration Read (DWORD): SOFTWARE\FSLogix\Profiles\DeleteLocalProfileWhenVHDShouldApply. Data: 1
    [09:01:18.410][tid:00000f34.00002bf8][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\FSLogixShellPath. Using default:
    [09:01:18.410][tid:00000f34.00002bf8][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\AccessNetworkAsComputerObject. Using default: 0
    [09:01:18.410][tid:00000f34.00002bf8][INFO] Accessing network as user object
    [09:01:18.410][tid:00000f34.00002bf8][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\AttachVHDSDDL. Using default:
    [09:01:18.411][tid:00000f34.00002bf8][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\ProfileType. Using default: 0
    [09:01:18.411][tid:00000f34.00002bf8][INFO] Profile type: Normal
    [09:01:18.411][tid:00000f34.00002bf8][INFO] Configuration Read (REG_SZ): SOFTWARE\FSLogix\Profiles\CCDLocations.
    [09:01:18.412][tid:00000f34.00002bf8][INFO] CCDLocations found - will use a Cloud Disk
    [09:01:18.412][tid:00000f34.00002bf8][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\DiffDiskParentFolderPath. Using default: C:\WINDOWS\TEMP\
    [09:01:18.413][tid:00000f34.00002bf8][INFO] Configuration Read (DWORD): SOFTWARE\FSLogix\Profiles\ClearCacheOnLogoff. Data: 1
    [09:01:18.413][tid:00000f34.00002bf8][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\CCDMachineId. Using default: WVD-01.Organization.local
    [09:01:18.413][tid:00000f34.00002bf8][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\FlipFlopProfileDirectoryName. Using default: 0
    [09:01:18.413][tid:00000f34.00002bf8][INFO] Configuration Read (REG_SZ): SOFTWARE\FSLogix\Profiles\SIDDirNamePattern. Data: %userdomain%-%username%
    [09:01:18.413][tid:00000f34.00002bf8][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\VHDNamePattern. Using default: Profile_%username%
    [09:01:18.414][tid:00000f34.00002bf8][INFO] Configuration Read (REG_SZ): SOFTWARE\FSLogix\Profiles\VolumeType. Data: VHDX
    [09:01:18.414][tid:00000f34.00002bf8][INFO] Configuration Read (REG_SZ): SOFTWARE\FSLogix\Profiles\SIDDirNameMatch. Data: %userdomain%-%username%
    [09:01:18.414][tid:00000f34.00002bf8][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\VHDNameMatch. Using default: Profile*
    [09:01:18.418][tid:00000f34.00002bf8][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\NoProfileContainingFolder. Using default: 0
    [09:01:18.456][tid:00000f34.00002bf8][INFO] Configuration Read (DWORD): SOFTWARE\FSLogix\Profiles\LockedRetryCount. Data: 1
    [09:01:18.456][tid:00000f34.00002bf8][INFO] Configuration Read (DWORD): SOFTWARE\FSLogix\Profiles\LockedRetryInterval. Data: 0
    [09:01:18.460][tid:00000f34.00002bf8][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\SIDDirSDDL. Using default:
    [09:01:18.497][tid:00000f34.00002bf8][INFO] Status set to 1: Cannot load user's profile
    [09:01:18.497][tid:00000f34.00002bf8][INFO] Error set to 33
    [09:01:18.498][tid:00000f34.00002bf8][ERROR:00000021] D:\agent_01_work\2\s\libraries\Frx.ServiceLib\Frx.Service.VHDProfileProvider.cpp(452): Frx.Service.VHDProfileProvider.cpp(452): [WCODE: 0x00000021] Could not acquire an exclusive lock for vhd(x): C:\ProgramData\FSLogix\Proxy\Organization-Testuser\Profile_Testuser.VHDX (The process cannot access the file because another process has locked a portion of the file.)
    [09:01:18.498][tid:00000f34.00002bf8][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\PreventLoginWithFailure. Using default: 0
    [09:01:18.500][tid:00000f34.00002bf8][ERROR:00000021] LoadProfile failed. User: Testuser. SID: S-1-5-21-687924372-4293999746-2831884817-1299. (The process cannot access the file because another process has locked a portion of the file.)
    [09:01:18.500][tid:00000f34.00002bf8][INFO] loadProfile time: 93 milliseconds
    [09:01:18.500][tid:00000f34.00002bf8][INFO] ===== End Session: LoadProfile: Testuser


    Wednesday, October 2, 2019 8:46 PM

All replies

  • @Marc-1983, When you are using cloud cache, the system is trying to perform locking across all the storage locations. What it's doing is creating a file in the location where the VHD gets stored that indicates the VHD is locked by another system. This file is named the same as your VHD file with a .lock extension. There should be some more information in your cloud cache logs related to this.

    The lock file contains some information about which machine is holding the lock, and when they last updated that they were doing so. It's not really a human readable format file, but I think you could type it and see what computer names it has in it. It seems likely that during testing maybe users are not logging out successfully so these lock files don't get cleaned up.

    If you know the file is not in use, you can safely delete the lock file.

    Tuesday, October 8, 2019 3:47 PM
    Moderator