Forum Discussion
User sessions being logged off while idle/disconnected
First time using FSLogix, we're on version 2.9.8612.60056 and just went out of dev to prod two weeks ago. We use it exclusively with Citrix. Everything seemed to be working fine in dev, but now out of 700 users, two of them have reported that when they are in our 'long jobs' farm, and they leave some heavy computational jobs running through the night (the whole purpose of this particular farm), they either just hit the 'disconnect' (never logout) button, or they just sleep their workstation and let the session window disconnect based on our group policy to disconnect idle sessions. But we don't have any policy in place on this farm to log anybody out. Yet it's happening for these users and I'm concerned that this is a pattern.
I have logging enabled on FSLogix and according to programdata\FSLogix\logs\Profile\profile-timestamp.log looks like it's between 490-510 minutes between the last activity of that profile, and then the tasks "===== Begin Session: EndShell" followed by "===== Begin Session: Logoff"
The user is never shown any error messages and their profiles aren't stuck in any sort of inconsistent state (at least not yet). They're always able to log back in the next morning, they're just irritated because they expected their running jobs to have been doing work all night, not logging them out and killing their progress.
While only 2 users have sent in tickets so far, I'm concerned that there might be more people affected who just haven't messaged the help desk yet. We ran regular roaming profiles for years and while it was incredibly slow in comparison and we don't want to go back to it, we never had this problem before switching to fslogix.
1 Reply
I used my test account to log in, then disconnect immediately several times. Each time it was exactly three hours between the logon, and then the unwanted logout.
[17:35:26.497][tid:00001758.000086d4][INFO] LoadProfile successful. Version: 2.9.8612.60056 User: zachguest. SID: S-1-5-21-2133283647-936784373-1860969634-33476. SessionId: 44
[17:35:26.497][tid:00001758.000086d4][INFO] loadProfile time: 1843 milliseconds
[17:35:26.497][tid:00001758.000086d4][INFO] ===== End Session: LoadProfile: zachguest
[17:35:26.497][tid:00001758.000086d4][INFO] ===== End Session: Logon
[17:35:35.233][tid:00001758.000086d4][INFO] ===== Begin Session: StartShell
[17:35:35.233][tid:00001758.000086d4][INFO] User: S-1-5-21-2133283647-936784373-1860969634-33476 (zachguest)
[17:35:35.233][tid:00001758.000086d4][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\LogonSyncMutexTimeout. Using default: 60000
[17:35:35.233][tid:00001758.000086d4][INFO] Acquired start shell lock for user zachguest (SID=S-1-5-21-2133283647-936784373-1860969634-33476) (Elapsed time: 0)
[17:35:35.233][tid:00001758.000086d4][INFO] Session configuration read (DWORD): SOFTWARE\FSLogix\Profiles\Sessions\S-1-5-21-2133283647-936784373-1860969634-33476\LogonStage = '1'(StartShell)
[17:35:35.248][tid:00001758.000086d4][INFO] Include group SID: S-1-5-21-2758785321-445443462-1569816914-1013
[17:35:35.248][tid:00001758.000086d4][INFO] Exclude group SID: S-1-5-21-2758785321-445443462-1569816914-1014
[17:35:35.248][tid:00001758.000086d4][INFO] User is a member of the include group
[17:35:35.248][tid:00001758.000086d4][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\IgnoreNonWVD. Using default: 0
[17:35:35.248][tid:00001758.000086d4][INFO] Configuration Read (DWORD): SOFTWARE\FSLogix\Profiles\Enabled. Data: 1
[17:35:35.248][tid:00001758.000086d4][INFO] Session configuration read (DWORD): SOFTWARE\FSLogix\Profiles\Sessions\S-1-5-21-2133283647-936784373-1860969634-33476\RefCount = '1'
[17:35:35.248][tid:00001758.000086d4][INFO] Checking Profile Data Export for S-1-5-21-2133283647-936784373-1860969634-33476
[17:35:35.248][tid:00001758.000086d4][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\SetTempToLocalPath. Using default: 3
[17:35:35.248][tid:00001758.000086d4][INFO] Initiating set up of TMP and TEMP environment variables to local disk
[17:35:35.248][tid:00001758.000086d4][INFO] Creating temp directory: C:\Users\local_zachguest\Temp
[17:35:35.248][tid:00001758.000086d4][INFO] Directory already exists
[17:35:35.248][tid:00001758.000086d4][INFO] Setting TMP and TEMP registry entries to: C:\Users\local_zachguest\Temp
[17:35:35.248][tid:00001758.000086d4][INFO] Setting INetCache folder
[17:35:35.263][tid:00001758.000086d4][INFO] INetCache folder successfully changed
[17:35:35.718][tid:00001758.000086d4][INFO] Profile data exported successfully
[17:35:35.718][tid:00001758.000086d4][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\OutlookCachedMode. Using default: 0
[17:35:35.718][tid:00001758.000086d4][INFO] Configuration setting not found: SOFTWARE\FSLogix\Apps\RoamSearch. Using default: 0
[17:35:35.718][tid:00001758.000086d4][INFO] Configuration setting not found: SOFTWARE\Policies\FSLogix\ODFC\RoamSearch. Using default: 0
[17:35:35.718][tid:00001758.000086d4][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\RoamSearch. Using default: 0
[17:35:35.718][tid:00001758.000086d4][INFO] Windows Per user Search is available. Search roaming is handled by the Operating System.
[17:35:35.718][tid:00001758.000086d4][INFO] Search is disabled
[17:35:35.718][tid:00001758.000086d4][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\EnableSpecialRoamingProfile. Using default: 0
[17:35:35.718][tid:00001758.000086d4][INFO] Session configuration wrote (DWORD): SOFTWARE\FSLogix\Profiles\Sessions\S-1-5-21-2133283647-936784373-1860969634-33476\EnableSpecialRoamingProfile = '0'
[17:35:35.718][tid:00001758.000086d4][INFO] Configuration setting not found: SOFTWARE\FSLogix\Apps\RoamRecycleBin. Using default: 1
[17:35:35.718][tid:00001758.000086d4][INFO] Added redirection C:\$RECYCLE.BIN\S-1-5-21-2133283647-936784373-1860969634-33476 -> \\?\Volume{35274f12-a82b-459d-96f0-daeaf19dd5a4}\PROFILE_RECYCLE.BIN
[17:35:35.718][tid:00001758.000086d4][INFO] Session configuration wrote (DWORD): SOFTWARE\FSLogix\Profiles\Sessions\S-1-5-21-2133283647-936784373-1860969634-33476\CleanupRecycleBin = '1'
[17:35:35.718][tid:00001758.000086d4][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\InstallAppxPackages. Using default: 1
[17:35:35.718][tid:00001758.000086d4][INFO] Session configuration wrote (DWORD): SOFTWARE\FSLogix\Profiles\Sessions\S-1-5-21-2133283647-936784373-1860969634-33476\InstallAppxPackages = '1'
[17:35:35.718][tid:00001758.000086d4][INFO] AppxPackage installation not supported
[17:35:35.718][tid:00001758.000086d4][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\FSLogixShellPath. Using default:
[17:35:35.718][tid:00001758.000086d4][INFO] Configuration Read (DWORD): SOFTWARE\FSLogix\Profiles\PreventLoginWithFailure. Data: 1
[17:35:35.718][tid:00001758.000086d4][INFO] Session configuration read (DWORD): SOFTWARE\FSLogix\Profiles\Sessions\S-1-5-21-2133283647-936784373-1860969634-33476\LogonStage = '5'(Logon_Complete)
[17:35:35.718][tid:00001758.000086d4][INFO] ===== End Session: StartShellthen, the logout:
[20:36:48.546][tid:00001758.0000804c][INFO] ===== Begin Session: EndShell
[20:36:48.546][tid:00001758.0000804c][INFO] User: S-1-5-21-2133283647-936784373-1860969634-33476 (zachguest)
[20:36:48.546][tid:00001758.0000804c][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\LogonSyncMutexTimeout. Using default: 60000
[20:36:48.546][tid:00001758.0000804c][INFO] Acquired end shell lock for user zachguest (SID=S-1-5-21-2133283647-936784373-1860969634-33476) (Elapsed time: 0)
[20:36:48.546][tid:00001758.0000804c][INFO] Session configuration read (REG_SZ): SOFTWARE\Policies\FSLogix\ODFC\Sessions\S-1-5-21-2133283647-936784373-1860969634-33476\ActivityId = '42e4acac-9010-4093-b209-b3b7339319e8'
[20:36:48.546][tid:00001758.0000804c][INFO] Session configuration read (DWORD): SOFTWARE\FSLogix\Profiles\Sessions\S-1-5-21-2133283647-936784373-1860969634-33476\LogonStage = '3'(EndShell)
[20:36:48.546][tid:00001758.0000804c][INFO] Session configuration read (DWORD): SOFTWARE\FSLogix\Profiles\Sessions\S-1-5-21-2133283647-936784373-1860969634-33476\InstallAppxPackages = '1'
[20:36:48.585][tid:00001758.0000804c][INFO] Session configuration read (DWORD): SOFTWARE\FSLogix\Profiles\Sessions\S-1-5-21-2133283647-936784373-1860969634-33476\EnableSpecialRoamingProfile = '0'
[20:36:48.585][tid:00001758.0000804c][INFO] Session configuration read (DWORD): SOFTWARE\FSLogix\Profiles\Sessions\S-1-5-21-2133283647-936784373-1860969634-33476\CleanupRecycleBin = '1'
[20:36:48.812][tid:00001758.0000804c][INFO] Removed redirection from C:\$RECYCLE.BIN\S-1-5-21-2133283647-936784373-1860969634-33476
[20:36:48.821][tid:00001758.0000804c][INFO] ===== End Session: EndShell
[20:36:53.440][tid:00001758.0000804c][INFO] ===== Begin Session: Logoff
[20:36:53.440][tid:00001758.0000804c][INFO] User: S-1-5-21-2133283647-936784373-1860969634-33476 (zachguest)
[20:36:53.440][tid:00001758.0000804c][INFO] Configuration setting not found: SOFTWARE\FSLogix\Profiles\LogonSyncMutexTimeout. Using default: 60000
[20:36:53.440][tid:00001758.0000804c][INFO] Acquired logoff lock for user zachguest (SID=S-1-5-21-2133283647-936784373-1860969634-33476) (Elapsed time: 0)
[20:36:53.440][tid:00001758.0000804c][INFO] Session configuration read (REG_SZ): SOFTWARE\FSLogix\Profiles\Sessions\S-1-5-21-2133283647-936784373-1860969634-33476\ActivityId = '42e4acac-9010-4093-b209-b3b7339319e8'
[20:36:53.440][tid:00001758.0000804c][INFO] Session configuration read (DWORD): SOFTWARE\FSLogix\Profiles\Sessions\S-1-5-21-2133283647-936784373-1860969634-33476\LogonStage = '4'(Logoff)This is totally bizarre. Surely there has to be some sort of log that would tell me what is instigating this logoff?
I have already turned on Advanced Audit policies of course, but on the particular machine in question, all it tells me is:
User initiated logoff:
Subject:
Security ID: domain\zachguest
Account Name: zachguest
Account Domain: domain
Logon ID: 0xB46747F9This event is generated when a logoff is initiated. No further user-initiated activity can occur. This event can be interpreted as a logoff event.
Something in zachguest's session is commanding a logout but I can't figure out what!
