Please Help, Unlock vs Login after lock
Rob Leonard
Hello all,
I have created a plugin that seems to function as expected with one exception. If the user locks the session and attempts to unlock it. Pgina (or rather my plugin) seems to freeze, if however instead the user hits crtl-alt-del and “changes user” but then authenticates through the plugin like an initial login attempt it “unlocks” the session and bring them in just fine. I have tried using the orig user to unlock setting to no avail.
During an “unlock” it definitely seems my plugin is being called but none of my logging steps are being hit so I can’t tell where. I am catching exceptions (as well as unhandled) so I would expect to see something here. Why/how is “unlock” operating differently than logging into a previously locked session? [Hope that makes sense]
Any/all help would be appreciated, I’ve been banging my head on this far too long I’m sure I’m missing something obvious.
-Rob
2015-01-22 11:29:20:994 AM [45|DEBUG] DuoPgina: [Session Change] pGina.Plugin.DuoPgina.Base.PluginBase.SessionChange(c:\Projects\Pgina Plugins\DuoPgina\DuoPgina\Base\PluginBase.cs:216) DuoPgina was notified of a session change.
2015-01-22 11:29:20:998 AM [45|INFO ] DuoPgina: [Session Change] pGina.Plugin.DuoPgina.Actions.HandleLogon(c:\Projects\Pgina Plugins\DuoPgina\DuoPgina\Actions.cs:590) {user} has logged in.
2015-01-22 11:29:21:009 AM [45|DEBUG] DuoPgina: [Session Change] pGina.Plugin.DuoPgina.Actions.HandleLogon(c:\Projects\Pgina Plugins\DuoPgina\DuoPgina\Actions.cs:622) Vendor {user} has logged in, their AutoLogOffTime is set to 1/22/2015 11:34 AM
2015-01-22 11:29:21:053 AM [45|DEBUG] DuoPgina: [Session Change] pGina.Plugin.DuoPgina.Settings.SetState(c:\Projects\Pgina Plugins\DuoPgina\DuoPgina\Settings.cs:400) Saving state file.
2015-01-22 11:29:21:983 AM [39|DEBUG] DuoPgina.Tray: [(null)] pGina.Plugin.DuoPgina.PipeMessaging.MessageServer.HandleLogMessage(c:\Projects\Pgina Plugins\DuoPgina\DuoPgina\PipeMessaging\MessageServer.cs:226) Tray notifier launched for user {user}
2015-01-22 11:29:22:764 AM [23|DEBUG] RemoteLog[NativeLib]: [(null)] pGina.Service.Impl.Service.HandleMessage(:0) [Provider.cpp:96] Stopping service state helper thread (if necessary)
2015-01-22 11:29:28:312 AM [27|DEBUG] RemoteLog[NativeLib]: [(null)] pGina.Service.Impl.Service.HandleMessage(:0) [Provider.cpp:88] Starting service state helper thread
2015-01-22 11:29:28:482 AM [45|INFO ] pGina.Service.Impl: [(null)] pGina.Service.Impl.Service.SessionChange(:0) SessionChange: 2 -> SessionLock
2015-01-22 11:29:28:485 AM [45|DEBUG] DuoPgina: [Session Change] pGina.Plugin.DuoPgina.Base.PluginBase.SessionChange(c:\Projects\Pgina Plugins\DuoPgina\DuoPgina\Base\PluginBase.cs:216) DuoPgina was notified of a session change.
2015-01-22 11:29:31:792 AM [13|DEBUG] RemoteLog[NativeLib]: [(null)] pGina.Service.Impl.Service.HandleMessage(:0) [CredentialProviderFilter.cpp:73] CredentialProviderFilter::Filter
2015-01-22 11:29:31:795 AM [19|DEBUG] RemoteLog[NativeLib]: [(null)] pGina.Service.Impl.Service.HandleMessage(:0) [Provider.cpp:121] Provider::SetUsageScenario(2, 0x00000000)
2015-01-22 11:29:31:801 AM [18|DEBUG] RemoteLog[NativeLib]: [(null)] pGina.Service.Impl.Service.HandleMessage(:0) [Provider.cpp:237] Provider::Advise(00000000019701A0, 0000000001970130) - provider events callback reference added
2015-01-22 11:29:31:808 AM [17|DEBUG] RemoteLog[NativeLib]: [(null)] pGina.Service.Impl.Service.HandleMessage(:0) [Provider.cpp:407] SerializedCredsAppearComplete: No serialized creds set
2015-01-22 11:29:31:810 AM [10|DEBUG] RemoteLog[NativeLib]: [(null)] pGina.Service.Impl.Service.HandleMessage(:0) [Provider.cpp:407] SerializedCredsAppearComplete: No serialized creds set
2015-01-22 11:29:31:812 AM [11|DEBUG] RemoteLog[NativeLib]: [(null)] pGina.Service.Impl.Service.HandleMessage(:0) [Credential.cpp:454] Retrieving user information from service.
2015-01-22 11:29:31:850 AM [20|DEBUG] RemoteLog[NativeLib]: [(null)] pGina.Service.Impl.Service.HandleMessage(:0) [Credential.cpp:458] Received: original uname: '{user}' uname: '{user}' domain: '{domain}'
2015-01-22 11:29:31:851 AM [30|DEBUG] RemoteLog[NativeLib]: [(null)] pGina.Service.Impl.Service.HandleMessage(:0) [Provider.cpp:365] GetCredentialAt: Non CredUI - returning an IID_IConnectableCredentialProviderCredential
2015-01-22 11:29:43:852 AM [31|DEBUG] RemoteLog[NativeLib]: [(null)] pGina.Service.Impl.Service.HandleMessage(:0) [Credential.cpp:601] Credential::Connect()
2015-01-22 11:29:43:855 AM [16|DEBUG] RemoteLog[NativeLib]: [(null)] pGina.Service.Impl.Service.HandleMessage(:0) [Credential.cpp:640] ProcessLoginAttempt: Processing login for {DOMAIN\USER}
2015-01-22 11:29:43:883 AM [29|DEBUG] PluginDriver:14ca6c7a-6e00-4a35-8350-130f7f89a8b2: [(null)] pGina.Core.PluginDriver..ctor(:0) New PluginDriver created
2015-01-22 11:29:43:884 AM [29|DEBUG] pGina.Service.Impl: [(null)] ? Processing LoginRequest for: {DOMAIN\USER} in session: 2 reason: Unlock
2015-01-22 11:29:43:886 AM [29|DEBUG] PluginDriver:14ca6c7a-6e00-4a35-8350-130f7f89a8b2: [(null)] pGina.Core.PluginDriver.BeginChain(:0) Begin login chain, 0 stateful plugin(s).
2015-01-22 11:29:43:887 AM [29|DEBUG] PluginDriver:14ca6c7a-6e00-4a35-8350-130f7f89a8b2: [(null)] pGina.Core.PluginDriver.ExecuteLoginChain(:0) Performing login process
2015-01-22 11:29:43:890 AM [29|DEBUG] PluginDriver:14ca6c7a-6e00-4a35-8350-130f7f89a8b2: [(null)] pGina.Core.PluginDriver.AuthenticateUser(:0) Authenticating user {DOMAIN\USER}, 1 plugins available
2015-01-22 11:29:43:891 AM [29|DEBUG] PluginDriver:14ca6c7a-6e00-4a35-8350-130f7f89a8b2: [(null)] pGina.Core.PluginDriver.AuthenticateUser(:0) Calling {my UUID}
Hans Wurst
2015-01-23 10:26:14,041 [1068|5|INFO ] pGina.Service.Impl: SessionChange: 2 -> SessionLock
2015-01-23 10:26:14,056 [1068|11|DEBUG] RemoteLog[NativeLib]: [CredentialProviderFilter.cpp:74] CredentialProviderFilter::Filter
2015-01-23 10:26:14,056 [1068|26|DEBUG] RemoteLog[NativeLib]: [CredentialProviderFilter.cpp:132] Filtering {6f45dc1e-5384-457a-bc13-2cd81b0d28ed}
2015-01-23 10:26:14,056 [1068|25|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:119] Provider::SetUsageScenario(2, 0x00000000)
2015-01-23 10:26:14,056 [1068|32|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:238] Provider::Advise(000000000137A320, 000000000137A340) - provider events callback reference added
2015-01-23 10:26:14,056 [1068|27|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:401] SerializedUserNameAvailable: No serialized creds set
2015-01-23 10:26:14,056 [1068|18|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:401] SerializedUserNameAvailable: No serialized creds set
2015-01-23 10:26:14,056 [1068|17|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:418] SerializedPasswordAvailable: No serialized creds set
2015-01-23 10:26:14,056 [1068|3|DEBUG] RemoteLog[NativeLib]: [Credential.cpp:546] Retrieving user information from service.
2015-01-23 10:26:14,072 [1068|31|DEBUG] RemoteLog[NativeLib]: [Credential.cpp:550] Received: original uname: 'user000' uname: 'user000' domain: 'WIN7EX32'
2015-01-23 10:26:14,072 [1068|24|DEBUG] RemoteLog[NativeLib]: [Credential.cpp:167] Credential::GetBitmapValue: Loading image from: c:\PROGRA~1\pGina\logo.bmp
2015-01-23 10:26:19,525 [1068|20|DEBUG] RemoteLog[NativeLib]: [Credential.cpp:335] Credential::GetSerialization: Processing login for user000
2015-01-23 10:26:19,572 [1068|19|DEBUG] PluginDriver:3c4fa477-e5a6-4a53-9ead-947ef429344b: New PluginDriver created
2015-01-23 10:26:19,572 [1068|19|INFO ] pgSMB: LoginUserRequest() user000 free to login
2015-01-23 10:26:19,572 [1068|19|INFO ] LocalMachine: LoginUserRequest() user000 free to login
2015-01-23 10:26:19,572 [1068|19|DEBUG] pGina.Service.Impl: Parse Request for: user000 in session: 2 reason: Unlock
2015-01-23 10:26:19,587 [1068|22|WARN ] RemoteLog[NativeLib]: Plugins did not set a domain name, assuming local machine!
2015-01-23 10:26:19,587 [1068|29|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:249] Provider::UnAdvise() - provider events callback reference released
2015-01-23 10:26:19,603 [1068|13|DEBUG] RemoteLog[NativeLib]: [Credential.cpp:455] Credential::ReportResult(0x00000000, 0x00000000) called
2015-01-23 10:26:19,603 [1068|136|INFO ] pGina.Service.Impl: SessionChange: 2 -> SessionUnlock
2015-01-23 10:26:20,634 [1068|12|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:94] Stopping service state helper thread (if necessary)
switch user/login (unlock)
2015-01-23 10:56:07,791 [1068|41|INFO ] pGina.Service.Impl: SessionChange: 1 -> SessionLock
2015-01-23 10:56:07,837 [1068|30|DEBUG] RemoteLog[NativeLib]: [CredentialProviderFilter.cpp:74] CredentialProviderFilter::Filter
2015-01-23 10:56:07,837 [1068|21|DEBUG] RemoteLog[NativeLib]: [CredentialProviderFilter.cpp:132] Filtering {6f45dc1e-5384-457a-bc13-2cd81b0d28ed}
2015-01-23 10:56:07,837 [1068|14|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:119] Provider::SetUsageScenario(2, 0x00000000)
2015-01-23 10:56:07,837 [1068|11|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:238] Provider::Advise(00000000013848B0, 00000000013848D0) - provider events callback reference added
2015-01-23 10:56:07,837 [1068|26|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:401] SerializedUserNameAvailable: No serialized creds set
2015-01-23 10:56:07,837 [1068|25|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:401] SerializedUserNameAvailable: No serialized creds set
2015-01-23 10:56:07,853 [1068|32|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:418] SerializedPasswordAvailable: No serialized creds set
2015-01-23 10:56:07,853 [1068|27|DEBUG] RemoteLog[NativeLib]: [Credential.cpp:546] Retrieving user information from service.
2015-01-23 10:56:07,853 [1068|17|DEBUG] RemoteLog[NativeLib]: [Credential.cpp:550] Received: original uname: 'user000' uname: 'user000' domain: 'WIN7EX32'
2015-01-23 10:56:07,853 [1068|3|DEBUG] RemoteLog[NativeLib]: [Credential.cpp:167] Credential::GetBitmapValue: Loading image from: c:\PROGRA~1\pGina\logo.bmp
2015-01-23 10:56:09,056 [1068|41|INFO ] pGina.Service.Impl: SessionChange: 1 -> ConsoleDisconnect
2015-01-23 10:56:09,166 [1068|15|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:249] Provider::UnAdvise() - provider events callback reference released
2015-01-23 10:56:09,353 [1068|31|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:87] Starting service state helper thread
2015-01-23 10:56:09,353 [1068|52|INFO ] pGina.Service.Impl: SessionChange: 2 -> ConsoleConnect
2015-01-23 10:56:09,509 [1068|16|DEBUG] RemoteLog[NativeLib]: [CredentialProviderFilter.cpp:74] CredentialProviderFilter::Filter
2015-01-23 10:56:09,509 [1068|20|DEBUG] RemoteLog[NativeLib]: [CredentialProviderFilter.cpp:132] Filtering {6f45dc1e-5384-457a-bc13-2cd81b0d28ed}
2015-01-23 10:56:09,509 [1068|22|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:119] Provider::SetUsageScenario(1, 0x00000000)
2015-01-23 10:56:09,525 [1068|29|DEBUG] RemoteLog[NativeLib]: [CredentialProviderFilter.cpp:74] CredentialProviderFilter::Filter
2015-01-23 10:56:09,525 [1068|19|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:238] Provider::Advise(00000000012CDF20, 00000000012CDE80) - provider events callback reference added
2015-01-23 10:56:09,525 [1068|13|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:401] SerializedUserNameAvailable: No serialized creds set
2015-01-23 10:56:09,525 [1068|12|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:401] SerializedUserNameAvailable: No serialized creds set
2015-01-23 10:56:09,525 [1068|10|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:418] SerializedPasswordAvailable: No serialized creds set
2015-01-23 10:56:09,525 [1068|9|DEBUG] RemoteLog[NativeLib]: [Credential.cpp:167] Credential::GetBitmapValue: Loading image from: c:\PROGRA~1\pGina\logo.bmp
2015-01-23 10:56:16,384 [1068|14|DEBUG] RemoteLog[NativeLib]: [Credential.cpp:335] Credential::GetSerialization: Processing login for user000
2015-01-23 10:56:16,384 [1068|11|DEBUG] PluginDriver:a97ee2e7-54fc-4361-b4c9-7648e8dbdac3: New PluginDriver created
2015-01-23 10:56:16,400 [1068|11|INFO ] pgSMB: LoginUserRequest() user000 free to login
2015-01-23 10:56:16,400 [1068|11|INFO ] LocalMachine: LoginUserRequest() user000 free to login
2015-01-23 10:56:16,400 [1068|11|DEBUG] pGina.Service.Impl: Processing LoginRequest for: user000 in session: 2 reason: Login
2015-01-23 10:56:16,416 [1068|11|DEBUG] pGina.Service.Impl: Interactive user:WIN7EX32\user000
2015-01-23 10:56:16,416 [1068|11|DEBUG] pGina.Service.Impl: User:user000 is Locked
2015-01-23 10:56:16,416 [1068|26|WARN ] RemoteLog[NativeLib]: Plugins did not set a domain name, assuming local machine!
2015-01-23 10:56:16,416 [1068|25|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:249] Provider::UnAdvise() - provider events callback reference released
2015-01-23 10:56:16,431 [1068|32|DEBUG] RemoteLog[NativeLib]: [Credential.cpp:455] Credential::ReportResult(0x00000000, 0x00000000) called
2015-01-23 10:56:16,462 [1068|52|INFO ] pGina.Service.Impl: SessionChange: 2 -> ConsoleDisconnect
2015-01-23 10:56:16,462 [1068|52|INFO ] pgSMB: SessionChange Event denied for ID:2
2015-01-23 10:56:16,462 [1068|52|INFO ] LocalMachine: SessionChange Event denied for ID:2
2015-01-23 10:56:16,587 [1068|52|INFO ] pGina.Service.Impl: SessionChange: 1 -> ConsoleConnect
2015-01-23 10:56:16,603 [1068|27|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:94] Stopping service state helper thread (if necessary)
2015-01-23 10:56:16,666 [1068|52|INFO ] pGina.Service.Impl: SessionChange: 1 -> SessionUnlock
2015-01-23 10:56:17,306 [1068|18|DEBUG] RemoteLog[NativeLib]: [Provider.cpp:94] Stopping service state helper thread (if necessary)
https://github.com/pgina/pgina/blob/master/pGina/src/Service/Impl/Service.cs#L254
pGina is simly processing the pluginchain by any loginrequest while
https://github.com/MutonUfoAI/pgina/blob/master/pGina/src/Service/Impl/Service.cs#L273
https://github.com/MutonUfoAI/pgina/blob/master/pGina/src/Service/Impl/Service.cs#L299
I'm asking who is already logged in, and only processing the pluginchain if the user is not.