opsi Loginblocker verzögert Anmeldung

[HSchweizer]

Hallo,

ich möchte gerne den opsi-client-agent auf allen Clients ausrollen.

Bis opsi 4.0.6 war das Verhalten des opsi_loginblocker so, dass sobald das Schloss-Symbol verschwindet, die Anmeldung freigegeben wird.
Man kann also direkt sein Kennwort eintippen. (Strg+Alt+Entf wird per GPO deaktiviert).

Mit der aktuellsten opsi Version (4.1) verhält es sich leider so, dass der Cursor im Kennwortfeld zwar direkt nach dem Verschwinden des Schloss-Symbols kurz blinkt, aber dann wieder für einige Sekunden die Tastatur gesperrt ist.
Der Cursor erscheint also erst wieder nach 5-6 Sekunden und man kann dann erst das Kennwort eingeben.

Windows 7 x64
opsi-client-agent_4.1.0.0-4

Der opsi-Server wurde komplett neu aufgesetzt.
Woran kann das liegen?

[n.wenselowski]

Hi,

der Loginblocker wurde seit opsi 4.0.6 überarbeitet.

Von deiner Beschreibung her bin ich mir nicht ganz sicher ob es sich wirklich noch um den Login-Blocker handelt, der da die Finger im Spiel hat - schließlich scheint er fertig.
Die Logs des Login-Blockers und des opsiclientd (diesen eventuell mit Log-Level 7 starten) in C:\opsi.org\log zeigen wann Aktionen gemacht werden.
Kannst du dort mal rein schauen, ob es wirklich der Login-Blocker ist?


Gruß

Niko

[HSchweizer]

Danke für die Antwort.

Wenn der opsi-client-agent noch nicht installiert ist, ist das Verhalten nicht so.
Es liegt also definitiv daran.

Was kann ich noch prüfen?

Was bedeutet nachfolgender Eintrag?
Could not open opsiclientd pipe \\.\pipe\opsiclientd: 2


Hier ein Auszug aus der opsi_loginblocker.log:

[5] 2018-06-06 11:00:32 ------------------------------------------------------------------------------------
[5] 2018-06-06 11:00:32 START OpsiLoginBlocker
[5] 2018-06-06 11:00:32 ------------------------------------------------------------------------------------
[5] 2018-06-06 11:00:32 Getting config from registry
[5] 2018-06-06 11:00:32 LoginBlockerLogLevel is: 5
[5] 2018-06-06 11:00:32 Read LoginBlockerLogDir from Registry and switch to Logfile 'c:\opsi.org\log'
[5] 2018-06-06 11:00:32 According to LoginBlockerLogDir Logfile='c:\opsi.org\log\opsi_loginblocker.log'
[5] 2018-06-06 11:00:32 LoginBlockerStart is: 1
[5] 2018-06-06 11:00:32 LoginBlockerTimeoutConnect is: 120 seconds
[5] 2018-06-06 11:00:32 Config read from registry.
[5] 2018-06-06 11:00:32 handleLogfileAging started.
[5] 2018-06-06 11:00:32 Check logfile age: 6.6.2018 - current date: 6.6.2018
[5] 2018-06-06 11:00:32 ------------------------------------------------------------------------
[5] 2018-06-06 11:00:32 Keep current logfile.
[5] 2018-06-06 11:00:32 ------------------------------------------------------------------------
[5] 2018-06-06 11:00:32 OS Version: 6.1 (Windows 7)
[5] 2018-06-06 11:00:32 Filtering credential providers
[5] 2018-06-06 11:00:32 Registry: start of opsiclientd service is enabled, waiting for service to start ...
[5] 2018-06-06 11:00:32 Service opsiclientd is not running (SERVICE_STOPPED)
[5] 2018-06-06 11:00:35 Service opsiclientd is running (SERVICE_RUNNING).
[4] 2018-06-06 11:00:35 Could not open opsiclientd pipe \\.\pipe\opsiclientd: 2
[5] 2018-06-06 11:00:36 Continue blocking!
[5] 2018-06-06 11:00:37 Continue blocking!
[5] 2018-06-06 11:00:38 Continue blocking!
[5] 2018-06-06 11:00:39 Continue blocking!
[5] 2018-06-06 11:00:40 Continue blocking!
[5] 2018-06-06 11:00:41 Continue blocking!
[5] 2018-06-06 11:00:42 Continue blocking!
[5] 2018-06-06 11:00:43 Continue blocking!
[5] 2018-06-06 11:00:44 Continue blocking!
[5] 2018-06-06 11:00:45 Continue blocking!
[5] 2018-06-06 11:00:46 Continue blocking!
[5] 2018-06-06 11:00:47 Continue blocking!
[5] 2018-06-06 11:00:48 Continue blocking!
[5] 2018-06-06 11:00:49 Continue blocking!
[5] 2018-06-06 11:00:50 Stop blocking!

[n.wenselowski]

Hi

Wenn der opsi-client-agent noch nicht installiert ist, ist das Verhalten nicht so.
Es liegt also definitiv daran.

Naja, dann ist auch noch kein Loginblocker drauf

Was kann ich noch prüfen?

Das opsiclientd-Log. Mit Loglevel 7. Das sollte mit den Timestamps aus dem Log des loginblockers sichtbar werden lassen, ob es Probleme gibt.
Und im Idealfall weißt du zu welchen Zeiten das Problem auftrat, damit du das mit den Logs abgleichen kannst.

Was bedeutet nachfolgender Eintrag?
Could not open opsiclientd pipe \\.\pipe\opsiclientd: 2

Die beiden Prozesse kommunizieren über eine Pipe (erstellt durch den opsiclientd) und die war zu dem Zeitpunkt noch nicht erstellt - es konnte noch keine Kommunikation laufen.


Gruß

Niko

[HSchweizer]

Ich habe zeitgleich auf die Uhr geschaut.

Um 17:30:59 verschwand das Schloss-Symbol und von opsi war nichts mehr zu sehen, wie auch im Log ersichtlich.
Um 17:31:00 hätte dann bereits eine Kennworteingabe möglich sein sollen.
Das war aber erst ca. 17:31:07 möglich, siehe unten.

"client connection lost" klingt nicht gut, was kann ich tun?
Vielen Dank.


opsiclientd.log:

[5] [Jun 06 17:30:58] [ event processing gui_startup ] No need to write config file 'C:\Program Files (x86)\opsi.org\opsi-client-agent\opsiclientd\opsiclientd.conf', config file is up to date (Config.pyo|366)
[7] [Jun 06 17:30:58] [ event processing gui_startup ] messageChanged: subject id 'message', message '' (Message.pyo|488)
[7] [Jun 06 17:30:58] [ event processing gui_startup ] sending notification 'messageChanged' to clients (Message.pyo|543)
[5] [Jun 06 17:30:58] [ event processing gui_startup ] Writing log to service (EventProcessing.pyo|257)
[7] [Jun 06 17:30:58] [ event processing gui_startup ] messageChanged: subject id 'status', message 'Übertrage Protokoll-Datei zum Service' (Message.pyo|488)
[7] [Jun 06 17:30:58] [ event processing gui_startup ] sending notification 'messageChanged' to clients (Message.pyo|543)
[7] [Jun 06 17:30:58] [ opsiclientd ] Executing jsonrpc method 'backend_exit' on host u'192.168.43.200' (JSONRPC.pyo|115)
[7] [Jun 06 17:30:58] [ opsiclientd ] Posting request... (JSONRPC.pyo|713)
[7] [Jun 06 17:30:58] [ opsiclientd ] Starting new HTTPS connection (0) to 192.168.43.200:4447 (HTTP.pyo|648)
[7] [Jun 06 17:30:58] [ opsiclientd ] Connection established to: 192.168.43.200 (HTTP.pyo|650)
[7] [Jun 06 17:30:58] [ opsiclientd ] Closing connection: <httplib.HTTPSConnection instance at 0x02F7D580> (HTTP.pyo|569)
[7] [Jun 06 17:30:58] [ opsiclientd ] Content-Type: gzip-application/json;charset=utf-8, Content-Encoding: deflate (JSONRPC.pyo|730)
[7] [Jun 06 17:30:58] [ opsiclientd ] Expecting deflated data from server (backwards compatible) (JSONRPC.pyo|738)
[5] [Jun 06 17:30:58] [ opsiclientd ] Shutdown request in Registry: 0 (Windows.pyo|327)
[5] [Jun 06 17:30:58] [ opsiclientd ] Reboot request in Registry: 0 (Windows.pyo|311)
[7] [Jun 06 17:30:58] [ event processing gui_startup ] messageChanged: subject id 'status', message 'Gebe Anmeldung frei' (Message.pyo|488)
[7] [Jun 06 17:30:58] [ event processing gui_startup ] sending notification 'messageChanged' to clients (Message.pyo|543)
[5] [Jun 06 17:30:58] [ opsiclientd ] Block login now set to 'False' (Opsiclientd.pyo|109)
[6] [Jun 06 17:30:58] [ opsiclientd ] Terminating block login notifier app (pid 2700) (Opsiclientd.pyo|146)
[7] [Jun 06 17:30:58] [ event processing gui_startup ] messageChanged: subject id 'status', message '' (Message.pyo|488)
[7] [Jun 06 17:30:58] [ event processing gui_startup ] sending notification 'messageChanged' to clients (Message.pyo|543)
[6] [Jun 06 17:30:58] [ event processing gui_startup ] Stopping notification server (EventProcessing.pyo|235)
[7] [Jun 06 17:30:58] [ event processing gui_startup ] sending notification 'endConnection' to clients (Message.pyo|543)
[7] [Jun 06 17:30:59] [ control pipe ] Connected to named pipe \\.\pipe\opsiclientd (ControlPipe.pyo|297)
[7] [Jun 06 17:30:59] [ control pipe ] Creating NTControlPipeConnection (ControlPipe.pyo|298)
[7] [Jun 06 17:30:59] [ control pipe ] NTControlPipeConnection initiated (ControlPipe.pyo|192)
[7] [Jun 06 17:30:59] [ control pipe ] NTControlPipeConnection thread started (ControlPipe.pyo|301)
[5] [Jun 06 17:30:59] [ event config software_on_demand] -----> Executing: getBlockLogin() (JsonRpc.pyo|134)
[6] [Jun 06 17:30:59] [ control pipe ] Creating pipe \\.\pipe\opsiclientd (ControlPipe.pyo|251)
[5] [Jun 06 17:30:59] [ opsiclientd ] rpc getBlockLogin: blockLogin is 'False' (ControlPipe.pyo|426)
[7] [Jun 06 17:30:59] [ control pipe ] Pipe \\.\pipe\opsiclientd created (ControlPipe.pyo|270)
[6] [Jun 06 17:30:59] [ event config software_on_demand] Got result (JsonRpc.pyo|142)
[7] [Jun 06 17:30:59] [ control pipe ] NTControlPipeConnection exiting (ControlPipe.pyo|237)
[7] [Jun 06 17:30:59] [ control pipe ] Connecting to named pipe \\.\pipe\opsiclientd (ControlPipe.pyo|291)
[6] [Jun 06 17:31:04] [ event processing gui_startup ] Notification server stopped (Message.pyo|636)
[5] [Jun 06 17:31:07] [ event processing gui_startup ] ============= EventProcessingThread for event 'gui_startup' ended ============= (EventProcessing.pyo|1276)
[6] [Jun 06 17:31:07] [ opsiclientd ] client connection lost (Message.pyo|448)
[5] [Jun 06 17:31:07] [ opsiclientd ] Done processing event '<ocdlib.Events.GUIStartupEvent object at 0x02E0ED10>' (Opsiclientd.pyo|419)
[5] [Jun 06 17:32:49] [ opsiclientd ] Session 'IXS77IrDfI2LSIVG4Az0A9cE8HDtiW40' from ip '127.0.0.1', application 'opsi jsonrpc module version 4.0.7.28' expired after 120 seconds (Session.pyo|190)
[6] [Jun 06 17:32:49] [ opsiclientd ] Session timer <_Timer(Thread-28, started daemon 4200)> canceled (Session.pyo|128)
[5] [Jun 06 17:32:49] [ opsiclientd ] Session 'IXS77IrDfI2LSIVG4Az0A9cE8HDtiW40' from ip '127.0.0.1', application 'opsi jsonrpc module version 4.0.7.28' deleted (Session.pyo|225)



opsi_loginblocker.log:

[5] 2018-06-06 17:30:40 ------------------------------------------------------------------------------------
[5] 2018-06-06 17:30:40 START OpsiLoginBlocker
[5] 2018-06-06 17:30:40 ------------------------------------------------------------------------------------
[5] 2018-06-06 17:30:40 Getting config from registry
[5] 2018-06-06 17:30:40 LoginBlockerLogLevel is: 5
[5] 2018-06-06 17:30:40 Read LoginBlockerLogDir from Registry and switch to Logfile 'c:\opsi.org\log'
[5] 2018-06-06 17:30:40 According to LoginBlockerLogDir Logfile='c:\opsi.org\log\opsi_loginblocker.log'
[5] 2018-06-06 17:30:40 LoginBlockerStart is: 1
[5] 2018-06-06 17:30:40 LoginBlockerTimeoutConnect is: 120 seconds
[5] 2018-06-06 17:30:40 Config read from registry.
[5] 2018-06-06 17:30:40 handleLogfileAging started.
[5] 2018-06-06 17:30:40 Check logfile age: 6.6.2018 - current date: 6.6.2018
[5] 2018-06-06 17:30:40 ------------------------------------------------------------------------
[5] 2018-06-06 17:30:40 Keep current logfile.
[5] 2018-06-06 17:30:40 ------------------------------------------------------------------------
[5] 2018-06-06 17:30:40 OS Version: 6.1 (Windows 7)
[5] 2018-06-06 17:30:40 Filtering credential providers
[5] 2018-06-06 17:30:40 Registry: start of opsiclientd service is enabled, waiting for service to start ...
[5] 2018-06-06 17:30:40 Service opsiclientd is not running (SERVICE_STOPPED)
[5] 2018-06-06 17:30:43 Service opsiclientd is running (SERVICE_RUNNING).
[4] 2018-06-06 17:30:43 Could not open opsiclientd pipe \\.\pipe\opsiclientd: 2
[5] 2018-06-06 17:30:44 Continue blocking!
[5] 2018-06-06 17:30:45 Continue blocking!
[5] 2018-06-06 17:30:46 Continue blocking!
[5] 2018-06-06 17:30:47 Continue blocking!
[5] 2018-06-06 17:30:48 Continue blocking!
[5] 2018-06-06 17:30:49 Continue blocking!
[5] 2018-06-06 17:30:50 Continue blocking!
[5] 2018-06-06 17:30:51 Continue blocking!
[5] 2018-06-06 17:30:52 Continue blocking!
[5] 2018-06-06 17:30:53 Continue blocking!
[5] 2018-06-06 17:30:54 Continue blocking!
[5] 2018-06-06 17:30:55 Continue blocking!
[5] 2018-06-06 17:30:56 Continue blocking!
[5] 2018-06-06 17:30:57 Continue blocking!
[5] 2018-06-06 17:30:58 Continue blocking!
[5] 2018-06-06 17:30:59 Stop blocking!