question

NickPanaccio-4293 avatar image
0 Votes"
NickPanaccio-4293 asked NickPanaccio-4293 answered

Random issue: Can't connect to existing FSLogix Profile container

I'm having issues with FSLogix over the last two days that has me stumped. The issue appears to be random, because it doesn't happen all the time. When I logon to my Citrix desktop (W10, 1912 CU2, FSL 2.9.7349), it doesn't always load my profile. Half of the time, it eventually times out and logs me on with a temporary local profile. The other half of the time, it loads just fine. In the Profile log, I see this:

 [07:43:22.779][tid:00001450.00000760][INFO]           ===== Begin Session: Logon
 [07:43:22.779][tid:00001450.00000760][INFO]            User: S-1-5-21-1275210071-220523388-725345543-251799 (testuser)
 [07:43:22.779][tid:00001450.00000760][INFO]            Acquiring mutex for user logon
 [07:43:22.779][tid:00001450.00000760][INFO]            Configuration setting not found: SOFTWARE\FSLogix\Profiles\LogonSyncMutexTimeout.  Using default: 60000
 [07:43:22.779][tid:00001450.00000760][INFO]            Mutex acquired
 [07:43:22.779][tid:00001450.00000760][INFO]           ===== Begin Session:  LoadProfile: testuser
 [07:43:22.779][tid:00001450.00000760][INFO]             Configuration Read (DWORD): SOFTWARE\FSLogix\Profiles\Enabled.  Data: 1
 [07:43:22.779][tid:00001450.00000760][INFO]             User: testuser. SID: S-1-5-21-1275210071-220523388-725345543-251799.
 [07:43:22.779][tid:00001450.00000760][INFO]             Include group SID: S-1-5-21-2750255506-3374091724-527744386-1150
 [07:43:22.779][tid:00001450.00000760][INFO]             Exclude group SID: S-1-5-21-2750255506-3374091724-527744386-1151
 [07:43:22.779][tid:00001450.00000760][INFO]             User is a member of the include group
 [07:43:22.779][tid:00001450.00000760][INFO]             Status set to 200: Setup in progress
 [07:43:22.779][tid:00001450.00000760][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\RedirectType.  Using default: 2
 [07:43:22.779][tid:00001450.00000760][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\ConcurrentUserSessions.  Using default: 1
 [07:43:22.779][tid:00001450.00000760][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\VolumeWaitTimeMS.  Using default: 20000
 [07:43:22.779][tid:00001450.00000760][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\DeleteLocalProfileWhenVHDShouldApply.  Using default: 0
 [07:43:22.779][tid:00001450.00000760][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\FSLogixShellPath.  Using default: 
 [07:43:22.779][tid:00001450.00000760][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\AccessNetworkAsComputerObject.  Using default: 0
 [07:43:22.779][tid:00001450.00000760][INFO]             Accessing network as user object
 [07:43:22.779][tid:00001450.00000760][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\AttachVHDSDDL.  Using default: 
 [07:43:22.779][tid:00001450.00000760][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\ProfileType.  Using default: 0
 [07:43:22.779][tid:00001450.00000760][INFO]             Profile type: Normal
 [07:43:22.779][tid:00001450.00000760][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\CCDLocations.  Using default: 
 [07:43:22.779][tid:00001450.00000760][INFO]             Configuration Read (REG_SZ): SOFTWARE\FSLogix\Profiles\VHDLocations.
 [07:43:22.779][tid:00001450.00000760][INFO]             VHDLocations found - configured to use Local Disk
 [07:43:22.779][tid:00001450.00000760][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\DiffDiskParentFolderPath.  Using default: C:\WINDOWS\TEMP\
 [07:43:22.779][tid:00001450.00000760][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\NoProfileContainingFolder.  Using default: 0
 [07:43:22.779][tid:00001450.00000760][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\FlipFlopProfileDirectoryName.  Using default: 0
 [07:43:22.779][tid:00001450.00000760][INFO]             Configuration Read (REG_SZ): SOFTWARE\FSLogix\Profiles\SIDDirNameMatch.  Data: %username%
 [07:43:22.779][tid:00001450.00000760][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\VHDNameMatch.  Using default: Profile*
 [07:43:22.779][tid:00001450.00000760][INFO]             Configuration Read (REG_SZ): SOFTWARE\FSLogix\Profiles\VolumeType.  Data: VHDX
 [07:43:55.391][tid:00001450.00000760][ERROR:00000043]   FindFile failed for path: \\domain.com\Citrix\FSLogix\testuser\Profile*.VHDX (The network name cannot be found.)
 [07:43:55.391][tid:00001450.00000760][INFO]             Configuration Read (REG_SZ): SOFTWARE\FSLogix\Profiles\SIDDirNamePattern.  Data: %username%
 [07:43:55.391][tid:00001450.00000760][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\VHDNamePattern.  Using default: Profile_%username%
 [07:45:00.429][tid:00001450.00000760][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\DisableRegistryLocalRedirect.  Using default: 1
 [07:45:00.429][tid:00001450.00000760][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\LockedRetryCount.  Using default: 12
 [07:45:00.429][tid:00001450.00000760][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\LockedRetryInterval.  Using default: 5
 [07:45:00.429][tid:00001450.00000760][INFO]             Profile VHD not found.  Creating new VHD.
 [07:45:00.429][tid:00001450.00000760][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\DirectAttachOnCreateVHD.  Using default: FALSE
 [07:45:00.429][tid:00001450.00000760][INFO]             Status set to 1: Cannot load user's profile
 [07:45:00.429][tid:00001450.00000760][INFO]             Error set to 1064
 [07:45:00.429][tid:00001450.00000760][ERROR:00000428]   Unable to find parent path of "" (An exception occurred in the service when handling the control request.)
 [07:45:00.429][tid:00001450.00000760][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\PreventLoginWithFailure.  Using default: 0
 [07:45:00.429][tid:00001450.00000760][ERROR:00000428]   LoadProfile failed.  User: testuser. SID: S-1-5-21-1275210071-220523388-725345543-251799. (An exception occurred in the service when handling the control request.)
 [07:45:00.429][tid:00001450.00000760][INFO]             loadProfile time: 97641 milliseconds
 [07:45:00.429][tid:00001450.00000760][INFO]           ===== End Session:  LoadProfile: testuser
 [07:45:00.429][tid:00001450.00000760][INFO]           ===== End Session: Logon
 [07:45:01.007][tid:00001450.00001ab0][INFO]           ===== Begin Session: Profile Directory Changed: S-1-5-21-1275210071-220523388-725345543-251799
 [07:45:01.007][tid:00001450.00001ab0][INFO]            New Profile Directory: C:\Users\testuser
 [07:45:01.007][tid:00001450.00001ab0][INFO]            Error set to 1064
 [07:45:01.007][tid:00001450.00001ab0][INFO]           ===== End Session: Profile Directory Changed: S-1-5-21-1275210071-220523388-725345543-251799
 [07:45:04.851][tid:00001450.00000760][INFO]           ===== Begin Session: StartShell
 [07:45:04.851][tid:00001450.00000760][INFO]            User: S-1-5-21-1275210071-220523388-725345543-251799 (testuser)
 [07:45:04.851][tid:00001450.00000760][INFO]            Acquiring mutex for user logon
 [07:45:04.851][tid:00001450.00000760][INFO]            Configuration setting not found: SOFTWARE\FSLogix\Profiles\LogonSyncMutexTimeout.  Using default: 60000
 [07:45:04.851][tid:00001450.00000760][INFO]            Mutex acquired
 [07:45:05.023][tid:00001450.00000760][INFO]           ===== Begin Session:  Logon notification: testuser
 [07:45:05.023][tid:00001450.00000760][INFO]             Session configuration read (REG_SZ): SOFTWARE\FSLogix\Profiles\Sessions\S-1-5-21-1275210071-220523388-725345543-251799\ActivityId = 'e91207fa-4330-0000-cb18-12e93043d701'
 [07:45:05.023][tid:00001450.00000760][INFO]             Configuration setting not found: SOFTWARE\FSLogix\Profiles\ConcurrentUserSessions.  Using default: 1
 [07:45:05.023][tid:00001450.00000760][INFO]             Checking Profile Data Export for S-1-5-21-1275210071-220523388-725345543-251799
 [07:45:05.023][tid:00001450.00000760][INFO]             Error set to 1064
 [07:45:05.023][tid:00001450.00000760][INFO]             No user VHD has been attached. This is not a profile we should handle
 [07:45:05.023][tid:00001450.00000760][INFO]           ===== End Session:  Logon notification: testuser
 [07:45:05.039][tid:00001450.00000760][INFO]           ===== End Session: StartShell

In Event Viewer, there are two related entries:

 The winlogon notification subscriber <frxsvc> took 97 second(s) to handle the notification event (Logon).
    
 The winlogon notification subscriber <frxsvc> is taking long time to handle the notification event (Logon).

My storage guys are looking into it, but so far saying everything looks fine. The containers are stored on a share on our EMC Isilon, accessed via a DFS path. Any ideas here? The randomness of it all is really throwing me off.

windows-server-fslogix
· 2
5 |1600 characters needed characters left characters exceeded

Up to 10 attachments (including images) can be used with a maximum of 3.0 MiB each and 30.0 MiB total.

To add to this, I'm also seeing this in my QA environment. Separate Citrix site, different OS build, latest FSL install - but same container storage SAN (different DFS path).

0 Votes 0 ·

HI NickPanaccio-4293,

1.Please enable below event log in eventviewer, when issue happen, we can write down the issue time and please go to below location to check if there are more related logs.
C:\Windows\System32\winevt\Logs
system.evtx
application.evtx
setup.evtx

Microsoft-Windows-SmbClient%4Connectivity.evtx
Microsoft-Windows-SmbClient%4Security.evtx
Microsoft-Windows-SmbClient%4Audit.evtx
Microsoft-Windows-SMBClient%4Operational.evtx
Microsoft-Windows-User Profile Service%4Operational.evtx
Microsoft-Windows-User Profile Service%4diagnostic.evtx need to enable it in eventvwer

0 Votes 0 ·

1 Answer

NickPanaccio-4293 avatar image
0 Votes"
NickPanaccio-4293 answered

We actually resolved this issue over the weekend. It looks like when our storage team added more front end nodes to our EMC Isilon, FSLogix started to fail 20% of the time. We went from 6 nodes to 10. Once we dropped Isilon back down to 6 nodes for this storage location, loading FSLogix profiles went back to a 100% success rate. I have no idea why that is, honestly. I opened a ticket with Microsoft, and the network engineer who looked at the Wireshark logs said that she couldn't even see it getting to the share itself.

· 4
5 |1600 characters needed characters left characters exceeded

Up to 10 attachments (including images) can be used with a maximum of 3.0 MiB each and 30.0 MiB total.

HI NickPanaccio-4293,

Thanks for sharing your experience.

There is a document for your store team reference.

Storage Recommendations for FSLogix

https://social.msdn.microsoft.com/Forums/en-US/d4a57f5b-0c24-4cb7-8efa-ea68b749a080/storage-recommendations-for-fslogix?forum=FSLogix

0 Votes 0 ·

Thanks, and yeah, I'm familiar with that article. It doesn't really cover the issue that we experienced, though. In fact, us being on Isilon made it that much harder to troubleshoot, because there aren't many in the community running FSL on Isilon, either.

0 Votes 0 ·

HI NickPanaccio-4293,

"because there aren't many in the community running FSL on Isilon, either."

Thanks for your understanding.

0 Votes 0 ·

HI NickPanaccio-4293,

I think we can accept your answer first, then it will help other IT friends to find it.


============================================
If the Answer is helpful, please click "Accept Answer" and upvote it.
Note: Please follow the steps in our documentation to enable e-mail notifications if you want to receive the related email notification for this thread.


0 Votes 0 ·