none
Profile VHD gets created first logon. Every logon afterwards uses local profile. RRS feed

  • Question

  • When a user logs in for the first time, the VHD gets created. When the user logs off and logs back on, a local user profile is created. 

    Event log shows EventID 26:

    LoadProfile failed.  User: testuser2. SID: S-1-5-21-792126803-1638606687-3217461627-5293. (A device attached to the system is not functioning.)

    Apparently FSLogix tries to recreate the disk, but aborts as the disk is already there...

    [19:57:00.024][tid:00009044.00009064][INFO]           ===== Begin Session: Logon
    [19:57:00.024][tid:00009044.00009064][INFO]            User: S-1-5-21-792126803-1638606687-3217461627-5293 (testuser2)
    [19:57:00.024][tid:00009044.00009064][INFO]            Acquiring mutex for user logon
    [19:57:00.024][tid:00009044.00009064][INFO]            Configuration setting not found: SOFTWARE\FSLogix\Profiles\LogonSyncMutexTimeout.  Using default: 60000
    [19:57:00.024][tid:00009044.00009064][INFO]            Mutex acquired
    [19:57:00.024][tid:00009044.00009064][INFO]           ===== Begin Session:  LoadProfile: testuser2
    [19:57:00.024][tid:00009044.00009064][INFO]             Configuration Read (DWORD): SOFTWARE\FSLogix\Profiles\Enabled.  Data: 1
    [19:57:00.024][tid:00009044.00009064][INFO]             User: testuser2. SID: S-1-5-21-792126803-1638606687-3217461627-5293.
    [19:57:00.024][tid:00009044.00009064][INFO]             Include group SID: S-1-5-21-3726100934-2596324139-785017062-1011
    [19:57:00.024][tid:00009044.00009064][INFO]             Exclude group SID: S-1-5-21-3726100934-2596324139-785017062-1012
    [19:57:00.024][tid:00009044.00009064][INFO]             User is a member of the include group
    [19:57:00.024][tid:00009044.00009064][INFO]             Status set to 200: Setup in progress
    [19:57:00.024][tid:00009044.00009064][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\RedirectType.  Using default: 2
    [19:57:00.024][tid:00009044.00009064][INFO]             Configuration Read (DWORD): SOFTWARE\FSLogix\Profiles\ConcurrentUserSessions.  Data: 0
    [19:57:00.024][tid:00009044.00009064][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\VolumeWaitTimeMS.  Using default: 20000
    [19:57:00.024][tid:00009044.00009064][INFO]             Configuration Read (DWORD): SOFTWARE\FSLogix\Profiles\DeleteLocalProfileWhenVHDShouldApply.  Data: 1
    [19:57:00.024][tid:00009044.00009064][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\FSLogixShellPath.  Using default: 
    [19:57:00.024][tid:00009044.00009064][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\AccessNetworkAsComputerObject.  Using default: 0
    [19:57:00.024][tid:00009044.00009064][INFO]             Accessing network as user object
    [19:57:00.024][tid:00009044.00009064][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\AttachVHDSDDL.  Using default: 
    [19:57:01.242][tid:00009044.00009064][INFO]             Successfully removed Profile for S-1-5-21-792126803-1638606687-3217461627-5293
    [19:57:01.242][tid:00009044.00009064][INFO]             Configuration Read (DWORD): SOFTWARE\FSLogix\Profiles\ProfileType.  Data: 1
    [19:57:01.242][tid:00009044.00009064][INFO]             Profile type: Read/Write
    [19:57:01.242][tid:00009044.00009064][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\CCDLocations.  Using default: 
    [19:57:01.242][tid:00009044.00009064][INFO]             Configuration Read (REG_SZ): SOFTWARE\FSLogix\Profiles\VHDLocations.
    [19:57:01.242][tid:00009044.00009064][INFO]             VHDLocations found - configured to use Local Disk
    [19:57:01.242][tid:00009044.00009064][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\DiffDiskParentFolderPath.  Using default: C:\windows\TEMP\
    [19:57:01.242][tid:00009044.00009064][INFO]             Configuration Read (DWORD): SOFTWARE\FSLogix\Profiles\NoProfileContainingFolder.  Data: 0
    [19:57:01.242][tid:00009044.00009064][INFO]             Configuration Read (DWORD): SOFTWARE\FSLogix\Profiles\FlipFlopProfileDirectoryName.  Data: 1
    [19:57:01.242][tid:00009044.00009064][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\VHDNameMatch.  Using default: Profile*
    [19:57:01.242][tid:00009044.00009064][INFO]             Configuration Read (REG_SZ): SOFTWARE\FSLogix\Profiles\VolumeType.  Data: VHDX
    [19:57:01.274][tid:00009044.00009064][INFO]             Configuration Read (REG_SZ): SOFTWARE\FSLogix\Profiles\VHDNamePattern.  Data: %username%.OST
    [19:57:01.274][tid:00009044.00009064][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\DisableRegistryLocalRedirect.  Using default: 1
    [19:57:01.274][tid:00009044.00009064][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\LockedRetryCount.  Using default: 12
    [19:57:01.274][tid:00009044.00009064][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\LockedRetryInterval.  Using default: 5
    [19:57:01.274][tid:00009044.00009064][INFO]             Profile VHD not found.  Creating new VHD.
    [19:57:01.274][tid:00009044.00009064][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\DirectAttachOnCreateVHD.  Using default: FALSE
    [19:57:01.274][tid:00009044.00009064][INFO]             Virtual HD type: vhd
    [19:57:01.274][tid:00009044.00009064][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\VHDXSectorSize.  Using default: 0
    [19:57:01.274][tid:00009044.00009064][INFO]             Virtual HD sector size: 0
    [19:57:01.274][tid:00009044.00009064][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\SizeInMBs.  Using default: 30000
    [19:57:01.274][tid:00009044.00009064][INFO]             Virtual HD size (MBs): 30000
    [19:57:01.274][tid:00009044.00009064][INFO]             Configuration Read (BOOL): SOFTWARE\FSLogix\Profiles\IsDynamic.  Data: TRUE
    [19:57:01.274][tid:00009044.00009064][INFO]             Virtual HD is: Dynamic
    [19:57:01.274][tid:00009044.00009064][INFO]           ===== Begin Session:   Create Formatted Disk
    [19:57:01.274][tid:00009044.00009064][ERROR:00000050]    VirtualDiskAPI::CreateFormattedDisk failed to create vhd(x): \\TH-XA-FSLX01\XAProfiles$\testuser2_S-1-5-21-792126803-1638606687-3217461627-5293\testuser2.OST.VHDX (The file exists.)
    [19:57:01.274][tid:00009044.00009064][INFO]           ===== End Session:   Create Formatted Disk
    [19:57:01.274][tid:00009044.00009064][INFO]             Status set to 9: Cannot create virtual disk
    [19:57:01.274][tid:00009044.00009064][INFO]             Error. Cleaning up.
    [19:57:01.274][tid:00009044.00009064][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\PreventLoginWithFailure.  Using default: 0
    [19:57:01.274][tid:00009044.00009064][ERROR:0000001f]   LoadProfile failed.  User: testuser2. SID: S-1-5-21-792126803-1638606687-3217461627-5293. (A device attached to the system is not functioning.)
    [19:57:01.274][tid:00009044.00009064][INFO]             loadProfile time: 1250 milliseconds
    [19:57:01.274][tid:00009044.00009064][INFO]           ===== End Session:  LoadProfile: testuser2
    [19:57:01.274][tid:00009044.00009064][INFO]           ===== End Session: Logon
    [19:57:01.571][tid:00009044.000092f8][INFO]           ===== Begin Session: Profile Directory Changed: S-1-5-21-792126803-1638606687-3217461627-5293
    [19:57:01.586][tid:00009044.000092f8][INFO]            New Profile Directory: C:\Users\testuser2
    [19:57:01.586][tid:00009044.000092f8][INFO]           ===== End Session: Profile Directory Changed: S-1-5-21-792126803-1638606687-3217461627-5293
    [19:59:57.462][tid:00009044.00001b48][INFO]           ===== Begin Session: StartShell
    [19:59:57.462][tid:00009044.00001b48][INFO]            User: S-1-5-21-792126803-1638606687-3217461627-5293 (testuser2)
    [19:59:57.462][tid:00009044.00001b48][INFO]            Acquiring mutex for user logon
    [19:59:57.462][tid:00009044.00001b48][INFO]            Configuration setting not found: SOFTWARE\FSLogix\Profiles\LogonSyncMutexTimeout.  Using default: 60000
    [19:59:57.462][tid:00009044.00001b48][INFO]            Mutex acquired
    [19:59:57.462][tid:00009044.00001b48][INFO]           ===== Begin Session:  Logon notification: testuser2
    [19:59:57.462][tid:00009044.00001b48][INFO]             Session configuration read (REG_SZ): SOFTWARE\FSLogix\Profiles\Sessions\S-1-5-21-792126803-1638606687-3217461627-5293\ActivityId = '69fdc1e4-760e-0002-d95e-ff690e76d501'
    [19:59:57.462][tid:00009044.00001b48][INFO]             Configuration Read (DWORD): SOFTWARE\FSLogix\Profiles\ConcurrentUserSessions.  Data: 0
    [19:59:57.462][tid:00009044.00001b48][INFO]             Checking Profile Data Export for S-1-5-21-792126803-1638606687-3217461627-5293
    [19:59:57.477][tid:00009044.00001b48][INFO]             Not a profile we care about
    [19:59:57.477][tid:00009044.00001b48][INFO]           ===== End Session:  Logon notification: testuser2
    [19:59:58.571][tid:00009044.00001b48][INFO]           ===== End Session: StartShell
    [20:01:54.290][tid:00009044.00003038][INFO]           ===== Begin Session: EndShell
    [20:01:54.290][tid:00009044.00003038][INFO]            User: S-1-5-21-792126803-1638606687-3217461627-5293 (testuser2)
    [20:01:54.290][tid:00009044.00003038][INFO]            Acquiring mutex for user logoff
    [20:01:54.290][tid:00009044.00003038][INFO]            Configuration setting not found: SOFTWARE\FSLogix\Profiles\LogonSyncMutexTimeout.  Using default: 60000
    [20:01:54.290][tid:00009044.00003038][INFO]            Mutex acquired
    [20:01:54.431][tid:00009044.00003038][INFO]            Session configuration read (REG_SZ): SOFTWARE\FSLogix\Profiles\Sessions\S-1-5-21-792126803-1638606687-3217461627-5293\ActivityId = '69fdc1e4-760e-0002-d95e-ff690e76d501'
    [20:01:54.446][tid:00009044.00003038][INFO]           ===== End Session: EndShell
    [20:01:55.477][tid:00009044.00003038][INFO]           ===== Begin Session: Logoff
    [20:01:55.477][tid:00009044.00003038][INFO]            User: S-1-5-21-792126803-1638606687-3217461627-5293 (testuser2)
    [20:01:55.477][tid:00009044.00003038][INFO]            Acquiring Lock for user logoff
    [20:01:55.477][tid:00009044.00003038][INFO]            Configuration setting not found: SOFTWARE\FSLogix\Profiles\LogonSyncMutexTimeout.  Using default: 60000
    [20:01:55.477][tid:00009044.00003038][INFO]            Mutex acquired
    [20:01:55.477][tid:00009044.00003038][INFO]           ===== Begin Session:  Unload profile: testuser2
    [20:01:55.477][tid:00009044.00003038][INFO]             User: testuser2. SID: S-1-5-21-792126803-1638606687-3217461627-5293.
    [20:01:55.477][tid:00009044.00003038][INFO]             Session configuration read (REG_SZ): SOFTWARE\FSLogix\Profiles\Sessions\S-1-5-21-792126803-1638606687-3217461627-5293\ActivityId = '69fdc1e4-760e-0002-d95e-ff690e76d501'
    [20:01:55.477][tid:00009044.00003038][INFO]             Configuration Read (DWORD): SOFTWARE\FSLogix\Profiles\ConcurrentUserSessions.  Data: 0
    [20:01:55.477][tid:00009044.00003038][INFO]             No teardown required
    [20:01:55.477][tid:00009044.00003038][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\ShutdownOnUserLogoff.  Using default: 0
    [20:01:55.477][tid:00009044.00003038][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\RebootOnUserLogoff.  Using default: 0
    [20:01:55.477][tid:00009044.00003038][INFO]             UnloadProfile successful.  User: testuser2. SID: S-1-5-21-792126803-1638606687-3217461627-5293.
    [20:01:55.477][tid:00009044.00003038][INFO]             unloadProfile time: 0 milliseconds
    [20:01:55.477][tid:00009044.00003038][INFO]           ===== End Session:  Unload profile: testuser2
    [20:01:55.477][tid:00009044.00003038][INFO]           ===== End Session: Logoff
    

    Anybody have any clue what is going on here?

    Saturday, September 28, 2019 6:09 PM

Answers

  • Hi,

    As suggested by Marc, your VHDNamePattern and VHDNameMatch should be aligned, otherwise default values may kick in.

    I can see that in line 30, in your log file the VHDNameMatch is not defined which means it defaults to Profile*.

    In line 32 you have defined a VHDNamePattern which is %username%, and because of that a testuser2.OST.VHDX is created.

    This presents a problem, because FSLogix is now via the VHDNameMatch, trying to match and mount a VHDX file with a Profile* prefix. Since it's not there, because the VHDX is called testuser2.ost.vhdx, it fails.

    Wednesday, October 2, 2019 3:48 AM

All replies

  • Running into the same issues, the first time the VHD is created and everything is working fine. The second time the users logs in it tries to recreate the VHD. Tried several options:

    - Checked the permissions (even assigned authenticated user full access permissions)

    - Removed the session profile in the registry

    - Changed the location

    - Checked if it was possible to open the share if the user was logged in with a temporary profile

    - Checked the eventlog: LoadProfile failed.  User: test . SID: S-1-5-21-2324661640-187141811-3889592194-1109. (A device attached to the system is not functioning.)

    Solved:

    1. Completely removed FSLogix including registry: Computer\HKEY_LOCAL_MACHINE\SOFTWARE\FSLogix

    2. Uninstalled the software

    3. Set the VHD Name pattern string option to not configured (was configured before and also tried the VHD name matching string, and that didn't work)

    Not entirely sure what the issue was. But as this is only a testing environment and fine i'm with it.





    • Edited by Marc-1983 Sunday, September 29, 2019 1:19 PM
    • Proposed as answer by Kasper Johansen Wednesday, October 2, 2019 3:48 AM
    Sunday, September 29, 2019 12:09 PM
  • Hi,

    As suggested by Marc, your VHDNamePattern and VHDNameMatch should be aligned, otherwise default values may kick in.

    I can see that in line 30, in your log file the VHDNameMatch is not defined which means it defaults to Profile*.

    In line 32 you have defined a VHDNamePattern which is %username%, and because of that a testuser2.OST.VHDX is created.

    This presents a problem, because FSLogix is now via the VHDNameMatch, trying to match and mount a VHDX file with a Profile* prefix. Since it's not there, because the VHDX is called testuser2.ost.vhdx, it fails.

    Wednesday, October 2, 2019 3:48 AM