opsiclientd startet langsam oder nicht
Verfasst: 29 Jul 2025, 12:47
Was sollte passieren?
Nach dem Boot wird der loginblocker aktiv, wartet bis opsiclientd läuft, dann beginnt die Verbindung zum Server und die Installation der Pakete.
Was ist passiert?
Das Verhalten ist leider inkonsistent
Möglichkeit a) Es funktioniert wie erwartet, opsiclientd startet nach wenigen Sekunden
Möglichkeit b) opsiclientd braucht etwa eine Minute um zu starten
opsiloginblocker.log
[...]
[1] [2025-07-25 14:18:49.639] [] opsi login blocker version 4.3.1.0 initialized on Windows 10 (or above)
[5] [2025-07-25 14:18:49.640] [] opsi com started
[5] [2025-07-25 14:18:49.641] [] Waiting for opsiclientd service to start
[5] [2025-07-25 14:18:49.642] [] Service opsiclientd is not running (SERVICE_STOPPED)
[5] [2025-07-25 14:18:49.724] [] Opsi credential provider filter init
[5] [2025-07-25 14:18:52.656] [] Service opsiclientd is starting (SERVICE_START_PENDING)
[5] [2025-07-25 14:18:55.662] [] Service opsiclientd is starting (SERVICE_START_PENDING)
[...]
[5] [2025-07-25 14:19:52.846] [] Service opsiclientd is starting (SERVICE_START_PENDING)
[5] [2025-07-25 14:19:55.851] [] Service opsiclientd is starting (SERVICE_START_PENDING)
[5] [2025-07-25 14:19:58.854] [] Service opsiclientd is running (SERVICE_RUNNING)
[4] [2025-07-25 14:19:58.854] [] Could not open opsiclientd pipe \\.\pipe\opsiclientd: 2
[4] [2025-07-25 14:19:59.865] [] Could not open opsiclientd pipe \\.\pipe\opsiclientd: 2
[4] [2025-07-25 14:20:00.876] [] Could not open opsiclientd pipe \\.\pipe\opsiclientd: 2
[5] [2025-07-25 14:20:01.888] [] Connected to opsiclientd pipe
[5] [2025-07-25 14:20:01.888] [] Sending request: '{"id": 1, "method": "registerClient", "params": ["opsi-login-blocker","4.3.1.0"]}'
[5] [2025-07-25 14:20:02.393] [] Received response: '{"id":1,"result":"client opsi-login-blocker/4.3.1.0/#1 registered","error":null}'
[5] [2025-07-25 14:20:03.910] [] Received request
[5] [2025-07-25 14:20:03.911] [] Sending response: '{"id": 1, "result": "blocking login", "error": null}'
[5] [2025-07-25 14:20:13.248] [] Received request
[5] [2025-07-25 14:20:13.249] [] Sending response: '{"id": 1, "result": "not blocking login", "error": null}'
[5] [2025-07-25 14:20:14.246] [] Filtering providers blockLogin=false, loginTriggered=false, rebootTriggered=false, shutdownTriggered=false
[5] [2025-07-25 14:20:14.304] [] Opsi credential provider init 1
[...]
opsiclientd.log startet erst danach
[1] [2025-07-25 14:19:58.095] [ ] Log file C:\opsi.org\log\opsiclientd.log started (__init__.py:135)
[...]
Ich habe aber auch einen Process Monitor Boot log laut dem opsiclientd.exe schon 14:18:51 startet und Sachen macht, vieles davor, während dieser warteminute wiederholt
14:19:23,3628674 opsiclientd.exe 6888 Thread Create SUCCESS Thread ID: 3232 NT AUTHORITY\SYSTEM
14:19:24,8516531 opsiclientd.exe 6888 Thread Exit SUCCESS Thread ID: 3232, User Time: 0.0000000, Kernel Time: 0.0000000 NT AUTHORITY\SYSTEM
Möglichkeit c)
opsiclientd startet gar nicht
Hier dann stattdessen im loginblockerlog
[1] [2025-07-28 15:56:16.500] [] opsi login blocker version 4.3.1.0 initialized on Windows 10 (or above)
[5] [2025-07-28 15:56:16.501] [] opsi com started
[5] [2025-07-28 15:56:16.501] [] Waiting for opsiclientd service to start
[5] [2025-07-28 15:56:16.530] [] Opsi credential provider filter init
[5] [2025-07-28 15:56:18.247] [] Service opsiclientd is starting (SERVICE_START_PENDING)
[5] [2025-07-28 15:56:21.256] [] Service opsiclientd is not running (SERVICE_STOPPED)
[5] [2025-07-28 15:56:24.258] [] Service opsiclientd is not running (SERVICE_STOPPED)
[...]
[5] [2025-07-28 15:58:15.489] [] Service opsiclientd is not running (SERVICE_STOPPED)
[5] [2025-07-28 15:58:18.497] [] Timed out while waiting for opsiclientd
opsiclientd_timeout.txt
1753711098 - opsi login blocker detected opsiclientd timeout at 2025-07-28 15:58:18
opsiclientd.log
[1] [2025-07-28 15:56:19.770] [ ] Log file C:\opsi.org\log\opsiclientd.log started (__init__.py:135)
[1] [2025-07-28 15:56:19.770] [opsiclientd ] opsiclientd service start (service.py:147)
[7] [2025-07-28 15:56:19.774] [ ] OpsiclientdService initiating (service.py:46)
[7] [2025-07-28 15:56:19.774] [ ] OpsiclientdService initiated (service.py:50)
[5] [2025-07-28 15:56:19.774] [ ] Handling start request (service.py:110)
[7] [2025-07-28 15:56:19.776] [ ] Reporting service status: 4 (service.py:64)
[7] [2025-07-28 15:56:19.776] [ ] Took 0.00 seconds to report service running status (service.py:114)
[2] [2025-07-28 15:56:19.780] [ ] opsiclientd crash (1722, 'RegisterEventSource/ReportEvent', 'The RPC server is unavailable.') (service.py:142)
Traceback (most recent call last):
File "opsiclientd\windows\service.py", line 117, in SvcRun
pywintypes.error: (1722, 'RegisterEventSource/ReportEvent', 'The RPC server is unavailable.')
Nach dem login ist dann
opsiclientd service stopped, rpcss running
Ich konnte das leider nicht nachvollziehen was mit diesem rpcss service ist, falls da jemand eine Idee hat wie man überprüfen kann ob der irgendwie länger zum starten braucht oder so gen her damit. Es scheint aber ja in Fall c) so zu sein das opsi direkt crashed ohne auf den noch zu warten.
Sind im Log Fehlermeldungen zu sehen?
Die oben angesprochenen logs oder weitere kann ich gern vollständig übermitteln wenn jemand interessiert ist.
Mit welchen Schritten kann das Problem nachgestellt werden?
Das ist leider etwas schwierig, wir haben ein paar Computer mit dem Problem, aber auch dutzende ohne, sowohl physische Laptops als auch VMs. Wenn ein Laptop einmal ein Problem hat scheint er zwischen verhalten b) und c) zu wechseln.
angefangen hat das ganze vor ~2 Monaten, evtl. auch seit wir auf Windows 11 24H2 umgestiegen sind, kommt dann sowohl bei upgegradeten als auch frisch installierten Geräten vor.
Bei welche Versionen der beteiligten Komponenten tritt das Problem auf?
Opsi Server ist aktuell, client-agent ist 4.3.13.5-3, war bei den letzten beiden monatlichen client-agent Versionen auch schon so
Stelle sicher, dass es die aktuellen Versionen aus den stable-Bereichen sind!
Wenn jemand eine Idee hat was ich weiter noch überprüfen könnte gern her damit, vielen Dank für eure Unterstützung!
Nach dem Boot wird der loginblocker aktiv, wartet bis opsiclientd läuft, dann beginnt die Verbindung zum Server und die Installation der Pakete.
Was ist passiert?
Das Verhalten ist leider inkonsistent
Möglichkeit a) Es funktioniert wie erwartet, opsiclientd startet nach wenigen Sekunden
Möglichkeit b) opsiclientd braucht etwa eine Minute um zu starten
opsiloginblocker.log
[...]
[1] [2025-07-25 14:18:49.639] [] opsi login blocker version 4.3.1.0 initialized on Windows 10 (or above)
[5] [2025-07-25 14:18:49.640] [] opsi com started
[5] [2025-07-25 14:18:49.641] [] Waiting for opsiclientd service to start
[5] [2025-07-25 14:18:49.642] [] Service opsiclientd is not running (SERVICE_STOPPED)
[5] [2025-07-25 14:18:49.724] [] Opsi credential provider filter init
[5] [2025-07-25 14:18:52.656] [] Service opsiclientd is starting (SERVICE_START_PENDING)
[5] [2025-07-25 14:18:55.662] [] Service opsiclientd is starting (SERVICE_START_PENDING)
[...]
[5] [2025-07-25 14:19:52.846] [] Service opsiclientd is starting (SERVICE_START_PENDING)
[5] [2025-07-25 14:19:55.851] [] Service opsiclientd is starting (SERVICE_START_PENDING)
[5] [2025-07-25 14:19:58.854] [] Service opsiclientd is running (SERVICE_RUNNING)
[4] [2025-07-25 14:19:58.854] [] Could not open opsiclientd pipe \\.\pipe\opsiclientd: 2
[4] [2025-07-25 14:19:59.865] [] Could not open opsiclientd pipe \\.\pipe\opsiclientd: 2
[4] [2025-07-25 14:20:00.876] [] Could not open opsiclientd pipe \\.\pipe\opsiclientd: 2
[5] [2025-07-25 14:20:01.888] [] Connected to opsiclientd pipe
[5] [2025-07-25 14:20:01.888] [] Sending request: '{"id": 1, "method": "registerClient", "params": ["opsi-login-blocker","4.3.1.0"]}'
[5] [2025-07-25 14:20:02.393] [] Received response: '{"id":1,"result":"client opsi-login-blocker/4.3.1.0/#1 registered","error":null}'
[5] [2025-07-25 14:20:03.910] [] Received request
[5] [2025-07-25 14:20:03.911] [] Sending response: '{"id": 1, "result": "blocking login", "error": null}'
[5] [2025-07-25 14:20:13.248] [] Received request
[5] [2025-07-25 14:20:13.249] [] Sending response: '{"id": 1, "result": "not blocking login", "error": null}'
[5] [2025-07-25 14:20:14.246] [] Filtering providers blockLogin=false, loginTriggered=false, rebootTriggered=false, shutdownTriggered=false
[5] [2025-07-25 14:20:14.304] [] Opsi credential provider init 1
[...]
opsiclientd.log startet erst danach
[1] [2025-07-25 14:19:58.095] [ ] Log file C:\opsi.org\log\opsiclientd.log started (__init__.py:135)
[...]
Ich habe aber auch einen Process Monitor Boot log laut dem opsiclientd.exe schon 14:18:51 startet und Sachen macht, vieles davor, während dieser warteminute wiederholt
14:19:23,3628674 opsiclientd.exe 6888 Thread Create SUCCESS Thread ID: 3232 NT AUTHORITY\SYSTEM
14:19:24,8516531 opsiclientd.exe 6888 Thread Exit SUCCESS Thread ID: 3232, User Time: 0.0000000, Kernel Time: 0.0000000 NT AUTHORITY\SYSTEM
Möglichkeit c)
opsiclientd startet gar nicht
Hier dann stattdessen im loginblockerlog
[1] [2025-07-28 15:56:16.500] [] opsi login blocker version 4.3.1.0 initialized on Windows 10 (or above)
[5] [2025-07-28 15:56:16.501] [] opsi com started
[5] [2025-07-28 15:56:16.501] [] Waiting for opsiclientd service to start
[5] [2025-07-28 15:56:16.530] [] Opsi credential provider filter init
[5] [2025-07-28 15:56:18.247] [] Service opsiclientd is starting (SERVICE_START_PENDING)
[5] [2025-07-28 15:56:21.256] [] Service opsiclientd is not running (SERVICE_STOPPED)
[5] [2025-07-28 15:56:24.258] [] Service opsiclientd is not running (SERVICE_STOPPED)
[...]
[5] [2025-07-28 15:58:15.489] [] Service opsiclientd is not running (SERVICE_STOPPED)
[5] [2025-07-28 15:58:18.497] [] Timed out while waiting for opsiclientd
opsiclientd_timeout.txt
1753711098 - opsi login blocker detected opsiclientd timeout at 2025-07-28 15:58:18
opsiclientd.log
[1] [2025-07-28 15:56:19.770] [ ] Log file C:\opsi.org\log\opsiclientd.log started (__init__.py:135)
[1] [2025-07-28 15:56:19.770] [opsiclientd ] opsiclientd service start (service.py:147)
[7] [2025-07-28 15:56:19.774] [ ] OpsiclientdService initiating (service.py:46)
[7] [2025-07-28 15:56:19.774] [ ] OpsiclientdService initiated (service.py:50)
[5] [2025-07-28 15:56:19.774] [ ] Handling start request (service.py:110)
[7] [2025-07-28 15:56:19.776] [ ] Reporting service status: 4 (service.py:64)
[7] [2025-07-28 15:56:19.776] [ ] Took 0.00 seconds to report service running status (service.py:114)
[2] [2025-07-28 15:56:19.780] [ ] opsiclientd crash (1722, 'RegisterEventSource/ReportEvent', 'The RPC server is unavailable.') (service.py:142)
Traceback (most recent call last):
File "opsiclientd\windows\service.py", line 117, in SvcRun
pywintypes.error: (1722, 'RegisterEventSource/ReportEvent', 'The RPC server is unavailable.')
Nach dem login ist dann
opsiclientd service stopped, rpcss running
Ich konnte das leider nicht nachvollziehen was mit diesem rpcss service ist, falls da jemand eine Idee hat wie man überprüfen kann ob der irgendwie länger zum starten braucht oder so gen her damit. Es scheint aber ja in Fall c) so zu sein das opsi direkt crashed ohne auf den noch zu warten.
Sind im Log Fehlermeldungen zu sehen?
Die oben angesprochenen logs oder weitere kann ich gern vollständig übermitteln wenn jemand interessiert ist.
Mit welchen Schritten kann das Problem nachgestellt werden?
Das ist leider etwas schwierig, wir haben ein paar Computer mit dem Problem, aber auch dutzende ohne, sowohl physische Laptops als auch VMs. Wenn ein Laptop einmal ein Problem hat scheint er zwischen verhalten b) und c) zu wechseln.
angefangen hat das ganze vor ~2 Monaten, evtl. auch seit wir auf Windows 11 24H2 umgestiegen sind, kommt dann sowohl bei upgegradeten als auch frisch installierten Geräten vor.
Bei welche Versionen der beteiligten Komponenten tritt das Problem auf?
Opsi Server ist aktuell, client-agent ist 4.3.13.5-3, war bei den letzten beiden monatlichen client-agent Versionen auch schon so
Stelle sicher, dass es die aktuellen Versionen aus den stable-Bereichen sind!
Wenn jemand eine Idee hat was ich weiter noch überprüfen könnte gern her damit, vielen Dank für eure Unterstützung!