win10-upgrade schlägt fehl / fehlender Loginblock

[andré]

Hi,

ich habe bei einem Rechner ein Problem mit dem windows10-upgrade Paket. Der Rechner loggt sich beim Schritt 3 nicht automatisch ein, das funktioniert aber bei mehreren anderen Geräten einwandfrei, die ich extra dafür getestet habe.

Erst dachte ich es liegt an den Registry-Einträgen zum Autologon. Die hier beschriebenen Registry-Werte habe ich gelöscht, hat nichts gebracht.

Nach weiterem Rumforschen ist mir aufgefallen, dass der Login in den opsi-setup-user nicht erfolgt, weil kein Login-Block stattfindet.

Während das in der opsi_loginblocker.log bei einem funktionierendem Rechner so aussieht:

Code: Alles auswählen

[5] [2022-12-22 15:22:29.678] [] Sending request: '{"id": 1, "method": "registerClient", "params": ["opsi-login-blocker","4.2.0.4"]}'
[5] [2022-12-22 15:22:29.695] [] Opsi credential provider filter init
[5] [2022-12-22 15:22:30.197] [] Received response: '{"id":1,"result":"client opsi-login-blocker/4.2.0.4/#1 registered","error":null}'
[5] [2022-12-22 15:22:30.463] [] Received request: '{"id":1,"method":"blockLogin","params":[true]}'
[5] [2022-12-22 15:22:30.464] [] Sending response: '{"id": 1, "result": "blocking login", "error": null}'
[5] [2022-12-22 15:22:43.988] [] Received request: '{"id":1,"method":"loginUser","params":["opsisetupuser","ZnhbKPe?OSa/9m"]}'
[5] [2022-12-22 15:22:43.989] [] Login user 'opsisetupuser'
[5] [2022-12-22 15:22:43.990] [] Credentials not initialized, waiting
[5] [2022-12-22 15:22:44.818] [] Filtering providers blockLogin=true, loginTriggered=true, rebootTriggered=false, shutdownTriggered=false
[5] [2022-12-22 15:22:44.872] [] Opsi credential provider init
[5] [2022-12-22 15:22:44.881] [] Hiding our tile (setting pdwCount to 0)
[5] [2022-12-22 15:22:45.009] [] Showing our tile (setting pdwCount to 1)
[5] [2022-12-22 15:22:45.272] [] Sending response: '{"id": 1, "result": true, "error": null}'
[1] [2022-12-22 15:38:12.011] []

hat der betroffene Rechner dieses Log:

Code: Alles auswählen

[5] [2022-12-22 17:50:48.786] [] Getting config from registry
[5] [2022-12-22 17:50:48.786] [] log level is: 5
[3] [2022-12-22 17:50:48.787] [] Failed to query registry key 80000002, subKey SOFTWARE\Microsoft\Windows\CurrentVersion\Authentication\Credential Provider Filters\{d2028e19-82fe-44c6-ad64-51497c97a02a}, valueName LoginBlockerLogDir: 234
[3] [2022-12-22 17:50:48.787] [] Failed to get LoginBlockerLogDir value from registry, using default
[5] [2022-12-22 17:50:48.787] [] OpsiCredentialProviderFilter is enabled
[5] [2022-12-22 17:50:48.788] [] OpsiCredentialProvider is enabled
[5] [2022-12-22 17:50:48.788] [] LoginBlockerTimeoutConnect is 120 seconds
[1] [2022-12-22 17:50:48.788] [] opsi login blocker version 4.2.0.4 initialized on Windows 10 (or above)
[5] [2022-12-22 17:50:48.789] [] opsi com started
[5] [2022-12-22 17:50:48.790] [] Waiting for opsiclientd service to start
[5] [2022-12-22 17:50:48.790] [] Service opsiclientd is running (SERVICE_RUNNING)
[5] [2022-12-22 17:50:48.791] [] Connected to opsiclientd pipe
[5] [2022-12-22 17:50:48.791] [] Sending request: '{"id": 1, "method": "registerClient", "params": ["opsi-login-blocker","4.2.0.4"]}'
[5] [2022-12-22 17:50:48.802] [] Opsi credential provider filter init
[5] [2022-12-22 17:50:49.297] [] Received response: '{"id":1,"result":"client opsi-login-blocker/4.2.0.4/#1 registered","error":null}'
[5] [2022-12-22 17:50:49.561] [] Received request: '{"id":1,"method":"blockLogin","params":[false]}'
[5] [2022-12-22 17:50:49.562] [] Sending response: '{"id": 1, "result": "not blocking login", "error": null}'
[5] [2022-12-22 17:50:49.815] [] Filtering providers blockLogin=false, loginTriggered=false, rebootTriggered=false, shutdownTriggered=false
[5] [2022-12-22 17:50:49.897] [] Opsi credential provider init
[5] [2022-12-22 17:50:49.909] [] Hiding our tile (setting pdwCount to 0)

Der Witz bei der Geschichte ist, dass der Rechner beim Schritt 4 kurz danach einen Login-Block durchführt:

Code: Alles auswählen

[1] [2022-12-22 17:53:41.273] [] opsi login blocker version 4.2.0.4 initializing on Windows 10 (or above) (credential provider filter)
[1] [2022-12-22 17:53:41.274] [] --------------------------------------------------------------------------------------------------------------
[5] [2022-12-22 17:53:41.274] [] Getting config from registry
[5] [2022-12-22 17:53:41.274] [] log level is: 5
[3] [2022-12-22 17:53:41.274] [] Failed to query registry key 80000002, subKey SOFTWARE\Microsoft\Windows\CurrentVersion\Authentication\Credential Provider Filters\{d2028e19-82fe-44c6-ad64-51497c97a02a}, valueName LoginBlockerLogDir: 234
[3] [2022-12-22 17:53:41.275] [] Failed to get LoginBlockerLogDir value from registry, using default
[5] [2022-12-22 17:53:41.275] [] OpsiCredentialProviderFilter is enabled
[5] [2022-12-22 17:53:41.275] [] OpsiCredentialProvider is enabled
[5] [2022-12-22 17:53:41.276] [] LoginBlockerTimeoutConnect is 120 seconds
[1] [2022-12-22 17:53:41.276] [] opsi login blocker version 4.2.0.4 initialized on Windows 10 (or above)
[5] [2022-12-22 17:53:41.276] [] opsi com started
[5] [2022-12-22 17:53:41.277] [] Waiting for opsiclientd service to start
[5] [2022-12-22 17:53:41.278] [] Service opsiclientd is running (SERVICE_RUNNING)
[5] [2022-12-22 17:53:41.278] [] Connected to opsiclientd pipe
[5] [2022-12-22 17:53:41.278] [] Sending request: '{"id": 1, "method": "registerClient", "params": ["opsi-login-blocker","4.2.0.4"]}'
[5] [2022-12-22 17:53:41.293] [] Opsi credential provider filter init
[5] [2022-12-22 17:53:41.793] [] Received response: '{"id":1,"result":"client opsi-login-blocker/4.2.0.4/#1 registered","error":null}'
[5] [2022-12-22 17:53:42.304] [] Received request: '{"id":1,"method":"blockLogin","params":[true]}'
[5] [2022-12-22 17:53:42.304] [] Sending response: '{"id": 1, "result": "blocking login", "error": null}'
[5] [2022-12-22 17:53:51.839] [] Received request: '{"id":1,"method":"rebootTriggered","params":[true]}'
[5] [2022-12-22 17:53:51.841] [] Sending response: '{"id": 1, "result": "reboot triggered", "error": null}'
[5] [2022-12-22 17:53:52.387] [] Filtering providers blockLogin=true, loginTriggered=false, rebootTriggered=true, shutdownTriggered=false
[5] [2022-12-22 17:53:55.494] [] Received request: '{"id":1,"method":"blockLogin","params":[false]}'
[5] [2022-12-22 17:53:55.494] [] Sending response: '{"id": 1, "result": "not blocking login", "error": null}'

Bei der Installation von anderen Programmen taucht ein Eintrag dazu auf, dass der Login geblockt wird. Soweit ich das sehe, betrifft das Problem nur diesen Rechner und nur das Paket windows10-upgrade.
Ich habe auch mal die opsiclientd.conf mit einem funktionierenden Rechner verglichen, die stimmen überein.

Den opsi-client-agent habe ich auf dem betroffenen Rechner auch schon neu installiert.

Ich setze aktuell folgende Versionen ein:
opsiconfd 4.2.0.298-1
opsi-client-agent 4.2.0.43-3 (trat auch bei der 4.2.0.42-1 auf)
windows10-upgrade 22h2-1

Irgendeine Idee, was ich da noch probieren könnte?


Edit:
Noch der entsprechende Teil aus dem Log des Upgrade-Pakets:

Code: Alles auswählen

(960)     [5] [2022-12-22 18:30:18.563] [windows10-upgrade]   comment: Triggering the auto logon
(961)     [6] [2022-12-22 18:30:18.563] [windows10-upgrade]   Switch : runOpsiScriptAsOpsiSetupUser
(962)     [6] [2022-12-22 18:30:18.563] [windows10-upgrade]     Case : loginOpsiSetupUser
(963)     [6] [2022-12-22 18:30:18.564] [windows10-upgrade]     EndCase
(964)     [6] [2022-12-22 18:30:18.564] [windows10-upgrade]     Case : runAsOpsiSetupUser
(965)     [6] [2022-12-22 18:30:18.564] [windows10-upgrade]     EndCase
(966)     [6] [2022-12-22 18:30:18.564] [windows10-upgrade]     Case : runOpsiScriptAsOpsiSetupUser
(967)     [6] [2022-12-22 18:30:18.564] [windows10-upgrade]     Case match: runOpsiScriptAsOpsiSetupUser = runOpsiScriptAsOpsiSetupUser
(968)     [5] [2022-12-22 18:30:18.565] [windows10-upgrade]       Execution of: opsiServiceCall_runOpsiScriptAsOpsiSetupUser /opsiclientd-once
(969)     [5] [2022-12-22 18:30:18.565] [windows10-upgrade]       
(972)     [6] [2022-12-22 18:30:18.565] [windows10-upgrade]            "method": "runOpsiScriptAsOpsiSetupUser"
(973)     [6] [2022-12-22 18:30:18.568] [windows10-upgrade]         SSL lib (path) should be: C:\Program Files (x86)\opsi.org\opsi-client-agent\opsi-script\libssl-1_1.dll
(976)     [6] [2022-12-22 18:30:18.612] [windows10-upgrade]         HTTPSender Post succeeded
(977)     [6] [2022-12-22 18:30:18.612] [windows10-upgrade]         Server-FQDN: localhost Server-IP: 127.0.0.1
(978)     [6] [2022-12-22 18:30:18.612] [windows10-upgrade]         JSON Bench for backend_info "params":[],"id":1} Start: 18:30:18:568 Time: 00:00:00:044
(979)     [6] [2022-12-22 18:30:40.863] [windows10-upgrade]         HTTPSender Post succeeded
(980)     [6] [2022-12-22 18:30:40.863] [windows10-upgrade]         Server-FQDN: localhost Server-IP: 127.0.0.1
(981)     [6] [2022-12-22 18:30:40.864] [windows10-upgrade]         JSON Bench for runOpsiScriptAsOpsiSetupUser "params":["windows10-upgrade\\localsetup\\setup-lo Start: 18:30:18:612 Time: 00:00:22:252
(982)     [3] [2022-12-22 18:30:40.864] [windows10-upgrade]         Error: retrieveJSONObject --- opsi service problem ----> {"message":"RuntimeError('No login capable opsi credential provider connected')","class":"RuntimeError"}
(983)     [3] [2022-12-22 18:30:40.864] [windows10-upgrade]         Received (first 512): {"id":1,"error":{"class":"RuntimeError","message":"RuntimeError('No login capable opsi credential provider connected')"},"result":null}
(984)     [3] [2022-12-22 18:30:40.864] [windows10-upgrade]         Error: -> {"message":"RuntimeError('No login capable opsi credential provider connected')","class":"RuntimeError"}
(985)     [6] [2022-12-22 18:31:40.857] [windows10-upgrade]       
(986)     [6] [2022-12-22 18:31:40.858] [windows10-upgrade]       ExitWindows set to Immediate Logout
(987)     [6] [2022-12-22 18:31:40.858] [windows10-upgrade]       Process stopped

[Andreas T.]

Hallo,

wir haben vor zwei Wochen drei Rechner mit dem Paket auf 22H2 aktualisiert und hatten bei einem Rechner das gleiche Problem. Die Rechner sollten eigentlich ziemlich gleich eingerichtet sein.

Wir haben einfach beim fehlschlagenden Rechner mal die win10-upgrade Property execution_method auf loginOpsiSetupUser gesetzt und das Upgrade lief durch. Vielleicht hilft dir das ja weiter. Wir haben leider nicht genauer nachvollzogen, was das Problem gewesen ist.

Viele Grüße,

Andreas

[andré]

Hi,

alles klar danke.
Den Hinweis auf loginOpsiSetupUser hatte ich hier auch in einem anderen Thread schon gelesen, bisher aber noch nicht getestet.
Diese Methode scheint auch bei diesem Notebook hier zu funktionieren.

Dir schöne Feiertage.

@uib: Ihr könnt ja mal Bescheid geben, ob ihr das näher in Augenschein nehmen wollt, dann würde ich den nächsten Rechner mit diesem Fehler bei uns zurückhalten, damit darauf getestet werden kann.

[Der-Matze]

Hallo André,

sorry ich habe den Beitrag eben erst entdeckt.
Gerne kommen wir auf dein Angebot zurück. Wenn ihr einen fehlerhaften Client habt würden wir uns über den kompletten Inhalt von C:\opsi.org\log als Zip Datei freuen.

Schöne Grüße
Matthias