Problem bei Shutdown-Installation

Antworten
andré
Beiträge: 324
Registriert: 07 Jan 2014, 10:48

Problem bei Shutdown-Installation

Beitrag von andré »

Hallo,

ich habe Freitag mehrere Pakete aktualisiert und beim Ausrollen auf einigen PCs ist mir aufgefallen, dass jeder Rechner Fehler geworfen hat. Stellte sich raus, dass beim Herunterfahren zwar Opsi aufgeht und die Installation beginnt, der Shutdown wird aber nicht angehalten und der Rechner geht nach 1 bis 2 Minuten einfach aus.

Das Problem tritt so erst auf, seit der opsi-client-agent auf Version 4.0.7-10 aktualisiert wurde. Sprich, vor ca. 2 Wochen trat es definitv noch nicht auf. Ein Client hat erst am 25.11. den client-agent aktualisiert, seitdem tritt das bei diesem Client auch auf.

Die "Wartezeit für das Ausführen von Gruppenrichtlinienskripts" (MaxGPOScriptWait) steht bei den Rechnern auf 15 Minuten und der Wert für den PreshutdownTimeout steht auf 3h, das sollte also nicht die Ursache sein.

Die Logdatei vom shutdown_starter sieht genauso aus, wie zu einem Zeitpunkt, an dem es funktioniert hat. Der Unterschied ist nur, dass es kein Log gibt, an dem am Ende Task completed steht.

Gibt es irgendeine Idee, woran das liegen könnte?

Grüße


Kurz nachdem Teil 2 durch ist, hören die Einträge im opsi_script-Log auf.

Teil 1 vom shutdown_starter-Log

Code: Alles auswählen

[1] [Nov 28 14:34:10:644] --
[1] [Nov 28 14:34:10:644] --
[1] [Nov 28 14:34:10:644] c:\opsi.org\log\\opsiclientd_shutdown_starter-part-1381294867.log
[1] [Nov 28 14:34:10:660] opsiclientd_shutdown_starter: version: 4.0.7.0
[5] [Nov 28 14:34:10:660] clientid=UrlVomClient
[5] [Nov 28 14:34:10:660] service_url=https://localhost:4441/opsiclientd
[5] [Nov 28 14:34:10:660] service_user=UrlVomClient
[5] [Nov 28 14:34:10:660] host_key=***(confidential)***
[5] [Nov 28 14:34:10:660] myevent=on_shutdown
[6] [Nov 28 14:34:10:660] Working with ssl protocol: sslvSSLv23 - auto negotation
[6] [Nov 28 14:34:10:912] JSON Bench for backend_info "params":[],"id":1} Start: 14:34:10:660 Time: 00:00:00:252
[6] [Nov 28 14:34:10:991] opsidata connected
[5] [Nov 28 14:34:10:991] init Connection done
[6] [Nov 28 14:34:10:991] JSON service request https://localhost:4441/opsiclientd isInstallationPending
[6] [Nov 28 14:34:11:039] JSON Bench for isInstallationPending "params":[],"id":1} Start: 14:34:10:991 Time: 00:00:00:048
[5] [Nov 28 14:34:11:118] resultstring={"id": 1, "result": false, "error": null}
[5] [Nov 28 14:34:11:118] No installation pending - fine
[6] [Nov 28 14:34:11:118] JSON service request https://localhost:4441/opsiclientd fireEvent
[6] [Nov 28 14:34:11:197] JSON Bench for fireEvent "params":["on_shutdown"],"id":1} Start: 14:34:11:118 Time: 00:00:00:079
[5] [Nov 28 14:34:11:275] resultstring={"id": 1, "result": null, "error": null}
[5] [Nov 28 14:34:11:275] Succesfull fired event: on_shutdown
[5] [Nov 28 14:34:16:328] calling: isEventRunning,[on_shutdown]
[6] [Nov 28 14:34:16:328] JSON service request https://localhost:4441/opsiclientd isEventRunning
[6] [Nov 28 14:34:16:375] JSON Bench for isEventRunning "params":["on_shutdown"],"id":1} Start: 14:34:16:328 Time: 00:00:00:047
[5] [Nov 28 14:34:16:454] resultstring={"id": 1, "result": true, "error": null}
[5] [Nov 28 14:34:21:522] calling: isEventRunning,[on_shutdown]
[6] [Nov 28 14:34:21:522] JSON service request https://localhost:4441/opsiclientd isEventRunning
[6] [Nov 28 14:34:21:949] JSON Bench for isEventRunning "params":["on_shutdown"],"id":1} Start: 14:34:21:522 Time: 00:00:00:427
[5] [Nov 28 14:34:22:028] resultstring={"id": 1, "result": true, "error": null}
[5] [Nov 28 14:34:27:080] calling: isEventRunning,[on_shutdown]
[6] [Nov 28 14:34:27:080] JSON service request https://localhost:4441/opsiclientd isEventRunning
[6] [Nov 28 14:34:27:127] JSON Bench for isEventRunning "params":["on_shutdown"],"id":1} Start: 14:34:27:080 Time: 00:00:00:047
[5] [Nov 28 14:34:27:206] resultstring={"id": 1, "result": true, "error": null}
[5] [Nov 28 14:34:32:244] calling: isEventRunning,[on_shutdown]
[6] [Nov 28 14:34:32:244] JSON service request https://localhost:4441/opsiclientd isEventRunning
[6] [Nov 28 14:34:32:289] JSON Bench for isEventRunning "params":["on_shutdown"],"id":1} Start: 14:34:32:244 Time: 00:00:00:045
[5] [Nov 28 14:34:32:374] resultstring={"id": 1, "result": true, "error": null}
[5] [Nov 28 14:34:37:417] calling: isEventRunning,[on_shutdown]
[6] [Nov 28 14:34:37:417] JSON service request https://localhost:4441/opsiclientd isEventRunning
[6] [Nov 28 14:34:37:455] JSON Bench for isEventRunning "params":["on_shutdown"],"id":1} Start: 14:34:37:417 Time: 00:00:00:038
[5] [Nov 28 14:34:37:592] resultstring={"id": 1, "result": true, "error": null}
[5] [Nov 28 14:34:42:610] calling: isEventRunning,[on_shutdown]
[6] [Nov 28 14:34:42:610] JSON service request https://localhost:4441/opsiclientd isEventRunning
[6] [Nov 28 14:34:42:656] JSON Bench for isEventRunning "params":["on_shutdown"],"id":1} Start: 14:34:42:610 Time: 00:00:00:046
[5] [Nov 28 14:34:42:742] resultstring={"id": 1, "result": true, "error": null}
[5] [Nov 28 14:34:47:760] calling: isEventRunning,[on_shutdown]
[6] [Nov 28 14:34:47:760] JSON service request https://localhost:4441/opsiclientd isEventRunning
[6] [Nov 28 14:34:47:805] JSON Bench for isEventRunning "params":["on_shutdown"],"id":1} Start: 14:34:47:760 Time: 00:00:00:045
[5] [Nov 28 14:34:47:890] resultstring={"id": 1, "result": true, "error": null}
[5] [Nov 28 14:34:52:909] calling: isEventRunning,[on_shutdown]
[6] [Nov 28 14:34:52:909] JSON service request https://localhost:4441/opsiclientd isEventRunning
[6] [Nov 28 14:34:52:962] JSON Bench for isEventRunning "params":["on_shutdown"],"id":1} Start: 14:34:52:909 Time: 00:00:00:053
[5] [Nov 28 14:34:53:050] resultstring={"id": 1, "result": true, "error": null}
[5] [Nov 28 14:34:58:069] calling: isEventRunning,[on_shutdown]
[6] [Nov 28 14:34:58:069] JSON service request https://localhost:4441/opsiclientd isEventRunning
[6] [Nov 28 14:34:58:114] JSON Bench for isEventRunning "params":["on_shutdown"],"id":1} Start: 14:34:58:069 Time: 00:00:00:045
[5] [Nov 28 14:34:58:202] resultstring={"id": 1, "result": true, "error": null}
[5] [Nov 28 14:35:03:221] calling: isEventRunning,[on_shutdown]
[6] [Nov 28 14:35:03:221] JSON service request https://localhost:4441/opsiclientd isEventRunning
[6] [Nov 28 14:35:03:342] JSON Bench for isEventRunning "params":["on_shutdown"],"id":1} Start: 14:35:03:221 Time: 00:00:00:121
[5] [Nov 28 14:35:03:498] resultstring={"id": 1, "result": true, "error": null}
[5] [Nov 28 14:35:08:517] calling: isEventRunning,[on_shutdown]
[6] [Nov 28 14:35:08:517] JSON service request https://localhost:4441/opsiclientd isEventRunning
[6] [Nov 28 14:35:08:553] JSON Bench for isEventRunning "params":["on_shutdown"],"id":1} Start: 14:35:08:517 Time: 00:00:00:036
[5] [Nov 28 14:35:08:644] resultstring={"id": 1, "result": true, "error": null}
[5] [Nov 28 14:35:13:664] calling: isEventRunning,[on_shutdown]
[6] [Nov 28 14:35:13:664] JSON service request https://localhost:4441/opsiclientd isEventRunning
[6] [Nov 28 14:35:13:741] JSON Bench for isEventRunning "params":["on_shutdown"],"id":1} Start: 14:35:13:664 Time: 00:00:00:077
[5] [Nov 28 14:35:13:825] resultstring={"id": 1, "result": true, "error": null}
[5] [Nov 28 14:35:18:843] calling: isEventRunning,[on_shutdown]
[6] [Nov 28 14:35:18:843] JSON service request https://localhost:4441/opsiclientd isEventRunning
[6] [Nov 28 14:35:18:877] JSON Bench for isEventRunning "params":["on_shutdown"],"id":1} Start: 14:35:18:843 Time: 00:00:00:034
[5] [Nov 28 14:35:18:966] resultstring={"id": 1, "result": true, "error": null}
[4] [Nov 28 14:35:23:984] Task aborted by timeout
Teil 2 vom shutdown_starter-Log

Code: Alles auswählen

[1] [Nov 28 14:35:24:106] --
[1] [Nov 28 14:35:24:106] --
[1] [Nov 28 14:35:24:106] c:\opsi.org\log\\opsiclientd_shutdown_starter-part-1355562307.log
[1] [Nov 28 14:35:24:106] opsiclientd_shutdown_starter: version: 4.0.7.0
[5] [Nov 28 14:35:24:106] clientid=w01ak.e94.bike24.net
[5] [Nov 28 14:35:24:106] service_url=https://localhost:4441/opsiclientd
[5] [Nov 28 14:35:24:106] service_user=w01ak.e94.bike24.net
[5] [Nov 28 14:35:24:106] host_key=***(confidential)***
[5] [Nov 28 14:35:24:106] myevent=on_shutdown
[6] [Nov 28 14:35:24:108] Working with ssl protocol: sslvSSLv23 - auto negotation
[6] [Nov 28 14:35:24:362] JSON Bench for backend_info "params":[],"id":1} Start: 14:35:24:108 Time: 00:00:00:253
[6] [Nov 28 14:35:24:450] opsidata connected
[5] [Nov 28 14:35:24:450] init Connection done
[6] [Nov 28 14:35:24:451] JSON service request https://localhost:4441/opsiclientd isInstallationPending
[6] [Nov 28 14:35:24:498] JSON Bench for isInstallationPending "params":[],"id":1} Start: 14:35:24:451 Time: 00:00:00:047
[5] [Nov 28 14:35:24:595] resultstring={"id": 1, "result": true, "error": null}
[2] [Nov 28 14:35:24:595] State installation pending detected, do not starting shutdown event.
[2] [Nov 28 14:35:24:595] Terminate called.
Und der noch die opsiclientd.log (der Länge wegen etwas gekürzt):

Code: Alles auswählen

[6] [Nov 28 14:34:10] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x02C72148> started processing   (Worker.pyo|251)
[5] [Nov 28 14:34:10] [ control server                ] New session created   (Session.pyo|184)
[5] [Nov 28 14:34:10] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsiclientd_event_starter.exe)   (ControlServer.pyo|162)
[5] [Nov 28 14:34:10] [ event config on_shutdown      ] -----> Executing: backend_info()   (JsonRpc.pyo|134)
[6] [Nov 28 14:34:10] [ event config on_shutdown      ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:34:10] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x02FD21C0> started processing   (Worker.pyo|251)
[6] [Nov 28 14:34:11] [ control server                ] Reusing session for client '127.0.0.1', application 'opsiclientd_event_starter.exe'   (Worker.pyo|397)
[5] [Nov 28 14:34:11] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsiclientd_event_starter.exe)   (ControlServer.pyo|162)
[5] [Nov 28 14:34:11] [ opsiclientd                   ] -----> Executing: isInstallationPending()   (JsonRpc.pyo|134)
[6] [Nov 28 14:34:11] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:34:11] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x02FD2148> started processing   (Worker.pyo|251)
[6] [Nov 28 14:34:11] [ control server                ] Reusing session for client '127.0.0.1', application 'opsiclientd_event_starter.exe'   (Worker.pyo|397)
[5] [Nov 28 14:34:11] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsiclientd_event_starter.exe)   (ControlServer.pyo|162)
[5] [Nov 28 14:34:11] [ opsiclientd                   ] -----> Executing: fireEvent(u'on_shutdown')   (JsonRpc.pyo|134)
[5] [Nov 28 14:34:11] [ opsiclientd                   ] Firing event 'on_shutdown'   (ControlServer.pyo|534)
[6] [Nov 28 14:34:11] [ event generator on_shutdown   ] Testing preconditions of configs: [<EventConfig: on_shutdown>]   (Events.pyo|403)
[6] [Nov 28 14:34:11] [ event generator on_shutdown   ] Firing event '<ocdlib.Events.CustomEvent object at 0x02FADC50>'   (Events.pyo|443)
[6] [Nov 28 14:34:11] [ event generator on_shutdown   ] Event info:   (Events.pyo|444)
[6] [Nov 28 14:34:11] [ event generator on_shutdown   ] Starting FireEventThread for listeners: [<OpsiclientdNT61(Thread-1, started daemon 564)>]   (Events.pyo|467)
[6] [Nov 28 14:34:11] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:34:11] [ event generator on_shutdown   ] Calling processEvent on listener <OpsiclientdNT61(Thread-1, started daemon 564)>   (Events.pyo|462)
[5] [Nov 28 14:34:11] [ opsiclientd                   ] Processing event <ocdlib.Events.CustomEvent object at 0x02FADC50>   (Opsiclientd.pyo|384)
[6] [Nov 28 14:34:11] [ event processing on_shutdown  ] Session id set to 1   (EventProcessing.pyo|173)
[5] [Nov 28 14:34:11] [ event processing on_shutdown  ] ============= EventProcessingThread for occurrcence of event 'on_shutdown' started =============   (EventProcessing.pyo|1116)
[5] [Nov 28 14:34:11] [ opsiclientd                   ] Block login now set to 'False'   (Opsiclientd.pyo|109)
[5] [Nov 28 14:34:11] [ event processing on_shutdown  ] Starting notification server on port 44003   (EventProcessing.pyo|194)
[6] [Nov 28 14:34:11] [ opsiclientd                   ] Notification server starting   (Message.pyo|594)
[5] [Nov 28 14:34:12] [ event processing on_shutdown  ] Notification server started   (EventProcessing.pyo|221)
[6] [Nov 28 14:34:12] [ event processing on_shutdown  ] Action processor name 'opsi-script', version '4.11.6.8'   (EventProcessing.pyo|351)
[5] [Nov 28 14:34:12] [ opsiclientd                   ] Block login now set to 'False'   (Opsiclientd.pyo|109)
[5] [Nov 28 14:34:12] [ event processing on_shutdown  ] Starting notifier application in session '1'   (EventProcessing.pyo|322)
[6] [Nov 28 14:34:12] [ opsiclientd                   ] Searching pids of process name winlogon.exe (session id: 1)   (Windows.pyo|1445)
[6] [Nov 28 14:34:12] [ opsiclientd                   ] Found process winlogon.exe with matching name (pid 840, session 1)   (Windows.pyo|1468)
[5] [Nov 28 14:34:12] [ opsiclientd                   ] Executing: 'C:\Program Files (x86)\opsi.org\opsi-client-agent\\opsiclientd_rpc.exe "UrlVomClient" "*** confidential ***" "4441" "setCurrentActiveDesktopName("1", System.getActiveDesktopName())"' in session '1' on desktop 'winsta0\winlogon'   (Windows.pyo|1632)
[6] [Nov 28 14:34:12] [ opsiclientd                   ] Process startet, pid: 3552   (Windows.pyo|1635)
[6] [Nov 28 14:34:12] [ opsiclientd                   ] Waiting for process ending: 3552 (timeout: 60 seconds)   (Windows.pyo|1638)
[6] [Nov 28 14:34:14] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x02FD2080> started processing   (Worker.pyo|251)
[5] [Nov 28 14:34:14] [ control server                ] New session created   (Session.pyo|184)
[5] [Nov 28 14:34:14] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsi jsonrpc module version 4.0.7.12)   (ControlServer.pyo|162)
[5] [Nov 28 14:34:14] [ event config gui_startup{installation_pending}] -----> Executing: backend_getInterface()   (JsonRpc.pyo|134)
[6] [Nov 28 14:34:14] [ event config gui_startup{installation_pending}] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:34:15] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x02FBDB98> started processing   (Worker.pyo|251)
[6] [Nov 28 14:34:15] [ control server                ] Reusing session for client '127.0.0.1', application 'opsi jsonrpc module version 4.0.7.12'   (Worker.pyo|397)
[5] [Nov 28 14:34:15] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsi jsonrpc module version 4.0.7.12)   (ControlServer.pyo|162)
[5] [Nov 28 14:34:15] [ opsiclientd                   ] -----> Executing: setCurrentActiveDesktopName(1, u'Winlogon')   (JsonRpc.pyo|134)
[5] [Nov 28 14:34:15] [ opsiclientd                   ] rpc setCurrentActiveDesktopName: current active desktop name for session 1 set to 'Winlogon'   (ControlServer.pyo|565)
[6] [Nov 28 14:34:15] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:34:16] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x02FBD0F8> started processing   (Worker.pyo|251)
[6] [Nov 28 14:34:16] [ control server                ] Reusing session for client '127.0.0.1', application 'opsiclientd_event_starter.exe'   (Worker.pyo|397)
[5] [Nov 28 14:34:16] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsiclientd_event_starter.exe)   (ControlServer.pyo|162)
[5] [Nov 28 14:34:16] [ opsiclientd                   ] -----> Executing: isEventRunning(u'on_shutdown')   (JsonRpc.pyo|134)
[6] [Nov 28 14:34:16] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:34:16] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x02FBA620> started processing   (Worker.pyo|251)
[6] [Nov 28 14:34:16] [ control server                ] Reusing session for client '127.0.0.1', application 'opsi jsonrpc module version 4.0.7.12'   (Worker.pyo|397)
[5] [Nov 28 14:34:16] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsi jsonrpc module version 4.0.7.12)   (ControlServer.pyo|162)

[...]

[5] [Nov 28 14:34:20] [ event processing on_shutdown  ] Config read   (Config.pyo|330)
[5] [Nov 28 14:34:20] [ event processing on_shutdown  ] Getting config from service   (EventProcessing.pyo|242)
[5] [Nov 28 14:34:20] [ event processing on_shutdown  ] Getting config from service   (Config.pyo|540)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId clientconfig.configserver.url, values [u'https://172.16.0.30:4447']   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Setting config value config_service.url   (Config.pyo|203)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId clientconfig.install_by_shutdown.active, values [False]   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId clientconfig.depot.drive, values [u'p:']   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Setting config value depot_server.drive   (Config.pyo|203)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId clientconfig.depot.dynamic, values [False]   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId clientconfig.depot.id, values [u'opsi.e94.bike24.net']   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Setting config value depot_server.depot_id   (Config.pyo|203)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId clientconfig.depot.protocol, values [u'cifs']   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId clientconfig.dhcpd.filename, values []   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId clientconfig.windows.domain, values [u'WORKGROUP']   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId configed.host_actions_disabled, values []   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId configed.host_displayfields, values [u'clientConnected', u'clientDescription', u'clientIPAddress', u'clientLastSeen', u'clientName']   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId configed.license_inventory_extradisplayfields, values []   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId configed.opsiclientd_events, values [u'on_demand']   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId configed.productonclient_displayfields_localboot, values [u'actionRequest', u'installationInfo', u'installationStatus', u'productId', u'versionInfo']   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId configed.productonclient_displayfields_netboot, values [u'actionRequest', u'installationInfo', u'installationStatus', u'productId', u'versionInfo']   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId configed.remote_control.ping_linux, values [u'xterm +hold -e ping %host%']   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId configed.remote_control.ping_linux.description, values [u'ping, started in a Linux environment']   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId configed.remote_control.ping_linux.editable, values [True]   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId configed.remote_control.ping_windows, values [u'cmd.exe /c start ping %host%']   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId configed.remote_control.ping_windows.description, values [u'ping, started in a Windows terminal']   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId configed.remote_control.ping_windows.editable, values [True]   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId configed.saved_search.product_failed.description, values [u'any product failed']   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId configed.ssh_config_active, values [False]   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId configed.ssh_menu_active, values [False]   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId configed.ssh_shell_active, values [False]   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId license-management.use, values [False]   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId opsi-linux-bootimage.append, values []   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId opsiclientd.config_service.connection_timeout, values [u'30']   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Setting config value config_service.connection_timeout   (Config.pyo|203)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId opsiclientd.event_gui_startup.active, values [True]   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Setting config value event_gui_startup.active   (Config.pyo|203)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId opsiclientd.event_net_connection.active, values [False]   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Setting config value event_net_connection.active   (Config.pyo|203)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId opsiclientd.event_timer.active, values [False]   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Setting config value event_timer.active   (Config.pyo|203)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId product_sort_algorithm, values [u'algorithm1']   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId software-on-demand.active, values [False]   (Config.pyo|574)
[6] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config state from service: configId software-on-demand.product-group-ids, values [u'software-on-demand']   (Config.pyo|574)
[5] [Nov 28 14:34:20] [ event processing on_shutdown  ] Got config from service   (Config.pyo|595)
[5] [Nov 28 14:34:20] [ event processing on_shutdown  ] Reconfiguring event generators   (EventProcessing.pyo|250)
[5] [Nov 28 14:34:20] [ event processing on_shutdown  ] Event config 'timer' is deactivated   (Events.pyo|918)
[5] [Nov 28 14:34:20] [ event processing on_shutdown  ] Event config 'user_login' is deactivated   (Events.pyo|918)
[5] [Nov 28 14:34:20] [ event processing on_shutdown  ] Event config 'net_connection' is deactivated   (Events.pyo|918)
[5] [Nov 28 14:34:20] [ event processing on_shutdown  ] Event config 'timer_silentinstall' is deactivated   (Events.pyo|918)
[5] [Nov 28 14:34:20] [ event processing on_shutdown  ] Event config 'gui_startup' added to event generator 'gui_startup'   (Events.pyo|1132)
[5] [Nov 28 14:34:20] [ event processing on_shutdown  ] Event config 'silent_install' added to event generator 'silent_install'   (Events.pyo|1132)
[5] [Nov 28 14:34:20] [ event processing on_shutdown  ] Event config 'on_shutdown' added to event generator 'on_shutdown'   (Events.pyo|1132)
[5] [Nov 28 14:34:20] [ event processing on_shutdown  ] Event config 'on_demand' added to event generator 'on_demand'   (Events.pyo|1132)
[5] [Nov 28 14:34:20] [ event processing on_shutdown  ] Event config 'sync_completed' added to event generator 'sync_completed'   (Events.pyo|1132)
[5] [Nov 28 14:34:20] [ event processing on_shutdown  ] Event config 'software_on_demand' added to event generator 'software_on_demand'   (Events.pyo|1132)
[5] [Nov 28 14:34:20] [ event processing on_shutdown  ] Updating config file: 'C:\Program Files (x86)\opsi.org\opsi-client-agent\opsiclientd\opsiclientd.conf'   (Config.pyo|334)
[5] [Nov 28 14:34:20] [ event processing on_shutdown  ] 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|365)
[5] [Nov 28 14:34:21] [ event processing on_shutdown  ]    [ 1] product firefox:             setup   (EventProcessing.pyo|651)
[5] [Nov 28 14:34:21] [ event processing on_shutdown  ]    [ 2] product flashplayer:         setup   (EventProcessing.pyo|651)
[5] [Nov 28 14:34:21] [ event processing on_shutdown  ]    [ 3] product sumatra:             setup   (EventProcessing.pyo|651)
[5] [Nov 28 14:34:21] [ event processing on_shutdown  ]    [ 4] product swaudit:             setup   (EventProcessing.pyo|651)
[5] [Nov 28 14:34:21] [ event processing on_shutdown  ]    [ 5] product thunderbird:         setup   (EventProcessing.pyo|651)
[5] [Nov 28 14:34:21] [ event processing on_shutdown  ] Start processing action requests   (EventProcessing.pyo|668)
[5] [Nov 28 14:34:21] [ event processing on_shutdown  ] Selecting depot for products [u'firefox', u'flashplayer', u'sumatra', u'swaudit', u'thunderbird']   (Config.pyo|391)
[5] [Nov 28 14:34:21] [ event processing on_shutdown  ] MasterOnly --> 'False'   (Config.pyo|392)
[6] [Nov 28 14:34:21] [ event processing on_shutdown  ] Dynamic depot selection disabled   (Config.pyo|448)
[6] [Nov 28 14:34:21] [ event processing on_shutdown  ] Master depot for products [u'firefox', u'flashplayer', u'sumatra', u'swaudit', u'thunderbird'] is opsi.e94.bike24.net   (Config.pyo|472)
[5] [Nov 28 14:34:21] [ event processing on_shutdown  ] Selected depot is: <OpsiConfigserver(id=u'opsi.e94.bike24.net', isMasterDepot=True)>   (Config.pyo|516)
[6] [Nov 28 14:34:21] [ event processing on_shutdown  ] Setting config value depot_server.depot_id   (Config.pyo|203)
[6] [Nov 28 14:34:21] [ event processing on_shutdown  ] Setting config value depot_server.url   (Config.pyo|203)
[6] [Nov 28 14:34:21] [ opsiclientd                   ] Searching pids of process name winlogon.exe (session id: 1)   (Windows.pyo|1445)
[6] [Nov 28 14:34:21] [ opsiclientd                   ] Found process winlogon.exe with matching name (pid 840, session 1)   (Windows.pyo|1468)
[5] [Nov 28 14:34:21] [ opsiclientd                   ] Executing: 'C:\Program Files (x86)\opsi.org\opsi-client-agent\\opsiclientd_rpc.exe "UrlVomClient" "*** confidential ***" "4441" "setCurrentActiveDesktopName("1", System.getActiveDesktopName())"' in session '1' on desktop 'winsta0\winlogon'   (Windows.pyo|1632)
[6] [Nov 28 14:34:21] [ opsiclientd                   ] Process startet, pid: 3336   (Windows.pyo|1635)
[6] [Nov 28 14:34:21] [ opsiclientd                   ] Waiting for process ending: 3336 (timeout: 60 seconds)   (Windows.pyo|1638)
[6] [Nov 28 14:34:21] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x02FBAEE0> started processing   (Worker.pyo|251)
[6] [Nov 28 14:34:21] [ control server                ] Reusing session for client '127.0.0.1', application 'opsiclientd_event_starter.exe'   (Worker.pyo|397)
[5] [Nov 28 14:34:21] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsiclientd_event_starter.exe)   (ControlServer.pyo|162)
[5] [Nov 28 14:34:21] [ opsiclientd                   ] -----> Executing: isEventRunning(u'on_shutdown')   (JsonRpc.pyo|134)
[6] [Nov 28 14:34:21] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:34:23] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x02FA9350> started processing   (Worker.pyo|251)
[5] [Nov 28 14:34:23] [ control server                ] New session created   (Session.pyo|184)
[5] [Nov 28 14:34:23] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsi jsonrpc module version 4.0.7.12)   (ControlServer.pyo|162)
[5] [Nov 28 14:34:23] [ opsiclientd                   ] -----> Executing: backend_getInterface()   (JsonRpc.pyo|134)
[6] [Nov 28 14:34:23] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:34:24] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x02FB7558> started processing   (Worker.pyo|251)
[6] [Nov 28 14:34:24] [ control server                ] Reusing session for client '127.0.0.1', application 'opsi jsonrpc module version 4.0.7.12'   (Worker.pyo|397)
[5] [Nov 28 14:34:24] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsi jsonrpc module version 4.0.7.12)   (ControlServer.pyo|162)
[5] [Nov 28 14:34:24] [ opsiclientd                   ] -----> Executing: setCurrentActiveDesktopName(1, u'Winlogon')   (JsonRpc.pyo|134)
[5] [Nov 28 14:34:24] [ opsiclientd                   ] rpc setCurrentActiveDesktopName: current active desktop name for session 1 set to 'Winlogon'   (ControlServer.pyo|565)
[6] [Nov 28 14:34:24] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:34:25] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x02FB7A58> started processing   (Worker.pyo|251)
[6] [Nov 28 14:34:25] [ control server                ] Reusing session for client '127.0.0.1', application 'opsi jsonrpc module version 4.0.7.12'   (Worker.pyo|397)
[5] [Nov 28 14:34:25] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsi jsonrpc module version 4.0.7.12)   (ControlServer.pyo|162)
[5] [Nov 28 14:34:25] [ opsiclientd                   ] -----> Executing: backend_exit()   (JsonRpc.pyo|134)
[6] [Nov 28 14:34:25] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[5] [Nov 28 14:34:25] [ opsiclientd                   ] Process 3336 ended with exit code 0   (Windows.pyo|1648)
[5] [Nov 28 14:34:25] [ event processing on_shutdown  ] Updating action processor   (EventProcessing.pyo|398)
[5] [Nov 28 14:34:25] [ event processing on_shutdown  ] Mounting depot share smb://opsi/opsi_depot   (EventProcessing.pyo|366)
[6] [Nov 28 14:34:25] [ event processing on_shutdown  ] Added depot 'opsi' to trusted domains   (EventProcessing.pyo|375)
[5] [Nov 28 14:34:25] [ event processing on_shutdown  ] Mounting '\\opsi\opsi_depot' to 'p:'   (Windows.pyo|775)
[5] [Nov 28 14:34:25] [ event processing on_shutdown  ] Updating action processor from depot dir 'p:\opsi-winst\\files\\opsi-winst'   (EventProcessing.pyo|445)
[5] [Nov 28 14:34:25] [ event processing on_shutdown  ] Local action processor exists and seems to be up to date   (EventProcessing.pyo|456)
[5] [Nov 28 14:34:25] [ event processing on_shutdown  ] Unmounting depot share   (EventProcessing.pyo|391)
[5] [Nov 28 14:34:25] [ event processing on_shutdown  ] Starting action processor in session '1' on desktop 'winlogon'   (EventProcessing.pyo|819)
[6] [Nov 28 14:34:25] [ event processing on_shutdown  ] Running command "C:\Program Files (x86)\opsi.org\opsi-client-agent\action_processor_starter.exe" "UrlVomClient" "*** confidential ***" "4441" "c:\\opsi.org\\log\\opsiclientd.log" "6" "smb://opsi/opsi_depot" "p:" "pcpatch" "*** confidential ***" "1" "winlogon" "\"C:\Program Files (x86)\opsi.org\opsi-client-agent\\opsi-winst\\winst32.exe\" /opsiservice \"https://172.16.0.30:4447\" /clientid UrlVomClient /username UrlVomClient /password *** confidential *** " 10800 "" "" false in session '1' on desktop 'winlogon'   (EventProcessing.pyo|298)
[6] [Nov 28 14:34:25] [ event processing on_shutdown  ] Searching pids of process name winlogon.exe (session id: 1)   (Windows.pyo|1445)
[6] [Nov 28 14:34:25] [ event processing on_shutdown  ] Found process winlogon.exe with matching name (pid 840, session 1)   (Windows.pyo|1468)
[5] [Nov 28 14:34:25] [ event processing on_shutdown  ] Executing: '"C:\Program Files (x86)\opsi.org\opsi-client-agent\action_processor_starter.exe" "UrlVomClient" "*** confidential ***" "4441" "c:\\opsi.org\\log\\opsiclientd.log" "6" "smb://opsi/opsi_depot" "p:" "pcpatch" "*** confidential ***" "1" "winlogon" "\"C:\Program Files (x86)\opsi.org\opsi-client-agent\\opsi-winst\\winst32.exe\" /opsiservice \"https://172.16.0.30:4447\" /clientid UrlVomClient /username UrlVomClient /password *** confidential *** " 10800 "" "" false' in session '1' on desktop 'winsta0\winlogon'   (Windows.pyo|1632)
[6] [Nov 28 14:34:25] [ event processing on_shutdown  ] Process startet, pid: 3328   (Windows.pyo|1635)
[6] [Nov 28 14:34:25] [ event processing on_shutdown  ] Waiting for process ending: 3328 (timeout: 0 seconds)   (Windows.pyo|1638)
[3] [Nov 28 14:34:26] [ action_processor_starter.exe  ] Failed to read version info from file u'/etc/opsi/version': [Errno 2] No such file or directory: u'/etc/opsi/version'   (Backend.pyo|206)
[6] [Nov 28 14:34:27] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x02FB75A8> started processing   (Worker.pyo|251)
[6] [Nov 28 14:34:27] [ control server                ] Reusing session for client '127.0.0.1', application 'opsiclientd_event_starter.exe'   (Worker.pyo|397)
[5] [Nov 28 14:34:27] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsiclientd_event_starter.exe)   (ControlServer.pyo|162)
[5] [Nov 28 14:34:27] [ opsiclientd                   ] -----> Executing: isEventRunning(u'on_shutdown')   (JsonRpc.pyo|134)
[6] [Nov 28 14:34:27] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:34:27] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x030ECBE8> started processing   (Worker.pyo|251)
[5] [Nov 28 14:34:27] [ control server                ] New session created   (Session.pyo|184)
[5] [Nov 28 14:34:27] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsi jsonrpc module version 4.0.7.12)   (ControlServer.pyo|162)
[5] [Nov 28 14:34:27] [ opsiclientd                   ] -----> Executing: backend_getInterface()   (JsonRpc.pyo|134)
[6] [Nov 28 14:34:27] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:34:27] [ action_processor_starter.exe  ] <JSONRPCBackend(host=u'localhost', deflate=False)>: Connected to service   (JSONRPC.pyo|497)
[6] [Nov 28 14:34:27] [ action_processor_starter.exe  ] Impersonating network account 'pcpatch'   (action_processor_starter.py|98)
[5] [Nov 28 14:34:27] [ action_processor_starter.exe  ] Mounting depot share smb://opsi/opsi_depot   (action_processor_starter.py|103)
[6] [Nov 28 14:34:28] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x02FB7C10> started processing   (Worker.pyo|251)
[6] [Nov 28 14:34:28] [ control server                ] Reusing session for client '127.0.0.1', application 'opsi jsonrpc module version 4.0.7.12'   (Worker.pyo|397)
[5] [Nov 28 14:34:28] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsi jsonrpc module version 4.0.7.12)   (ControlServer.pyo|162)
[5] [Nov 28 14:34:28] [ opsiclientd                   ] -----> Executing: setStatusMessage(u'1', u'Verbinde mit Depot-Freigabe smb://opsi/opsi_depot')   (JsonRpc.pyo|134)
[5] [Nov 28 14:34:28] [ opsiclientd                   ] DEBUG: [<EventProcessingThread(Thread-56, started daemon 1376)>]    (Opsiclientd.pyo|431)
[5] [Nov 28 14:34:28] [ opsiclientd                   ] DEBUG: 1    (Opsiclientd.pyo|433)
[5] [Nov 28 14:34:28] [ opsiclientd                   ] rpc setStatusMessage: Setting status message to 'Verbinde mit Depot-Freigabe smb://opsi/opsi_depot'   (ControlServer.pyo|541)
[6] [Nov 28 14:34:28] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[5] [Nov 28 14:34:28] [ action_processor_starter.exe  ] Mounting '\\opsi\opsi_depot' to 'p:'   (Windows.pyo|775)
[5] [Nov 28 14:34:28] [ action_processor_starter.exe  ] Starting action processor   (action_processor_starter.py|112)
[6] [Nov 28 14:34:29] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x0315ED28> started processing   (Worker.pyo|251)
[6] [Nov 28 14:34:29] [ control server                ] Reusing session for client '127.0.0.1', application 'opsi jsonrpc module version 4.0.7.12'   (Worker.pyo|397)
[5] [Nov 28 14:34:29] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsi jsonrpc module version 4.0.7.12)   (ControlServer.pyo|162)
[5] [Nov 28 14:34:29] [ opsiclientd                   ] -----> Executing: setStatusMessage(u'1', u'Action processor l\xe4uft')   (JsonRpc.pyo|134)
[5] [Nov 28 14:34:29] [ opsiclientd                   ] DEBUG: [<EventProcessingThread(Thread-56, started daemon 1376)>]    (Opsiclientd.pyo|431)
[5] [Nov 28 14:34:29] [ opsiclientd                   ] DEBUG: 1    (Opsiclientd.pyo|433)
[5] [Nov 28 14:34:29] [ opsiclientd                   ] rpc setStatusMessage: Setting status message to 'Action processor läuft'   (ControlServer.pyo|541)
[6] [Nov 28 14:34:29] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[5] [Nov 28 14:34:29] [ action_processor_starter.exe  ] Running command '"C:\Program Files (x86)\opsi.org\opsi-client-agent\\opsi-winst\\winst32.exe" /opsiservice "https://172.16.0.30:4447" /clientid UrlVomClient /username UrlVomClient /password *** confidential *** ' as user 'pcpatch' on desktop 'winlogon'   (Windows.pyo|1926)
[6] [Nov 28 14:34:29] [ action_processor_starter.exe  ] Process startet, pid: 3352   (Windows.pyo|1929)
[6] [Nov 28 14:34:29] [ action_processor_starter.exe  ] Waiting for process ending: 3352 (timeout: 10800 seconds)   (Windows.pyo|1932)
[6] [Nov 28 14:34:32] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x0315ED78> started processing   (Worker.pyo|251)
[6] [Nov 28 14:34:32] [ control server                ] Reusing session for client '127.0.0.1', application 'opsiclientd_event_starter.exe'   (Worker.pyo|397)
[5] [Nov 28 14:34:32] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsiclientd_event_starter.exe)   (ControlServer.pyo|162)
[5] [Nov 28 14:34:32] [ opsiclientd                   ] -----> Executing: isEventRunning(u'on_shutdown')   (JsonRpc.pyo|134)
[6] [Nov 28 14:34:32] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:34:37] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x02FB7558> started processing   (Worker.pyo|251)
[6] [Nov 28 14:34:37] [ control server                ] Reusing session for client '127.0.0.1', application 'opsiclientd_event_starter.exe'   (Worker.pyo|397)
[5] [Nov 28 14:34:37] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsiclientd_event_starter.exe)   (ControlServer.pyo|162)
[5] [Nov 28 14:34:37] [ opsiclientd                   ] -----> Executing: isEventRunning(u'on_shutdown')   (JsonRpc.pyo|134)
[6] [Nov 28 14:34:37] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:34:42] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x02FB7080> started processing   (Worker.pyo|251)
[6] [Nov 28 14:34:42] [ control server                ] Reusing session for client '127.0.0.1', application 'opsiclientd_event_starter.exe'   (Worker.pyo|397)
[5] [Nov 28 14:34:42] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsiclientd_event_starter.exe)   (ControlServer.pyo|162)
[5] [Nov 28 14:34:42] [ opsiclientd                   ] -----> Executing: isEventRunning(u'on_shutdown')   (JsonRpc.pyo|134)
[6] [Nov 28 14:34:42] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:34:47] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x02FB76C0> started processing   (Worker.pyo|251)
[6] [Nov 28 14:34:47] [ control server                ] Reusing session for client '127.0.0.1', application 'opsiclientd_event_starter.exe'   (Worker.pyo|397)
[5] [Nov 28 14:34:47] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsiclientd_event_starter.exe)   (ControlServer.pyo|162)
[5] [Nov 28 14:34:47] [ opsiclientd                   ] -----> Executing: isEventRunning(u'on_shutdown')   (JsonRpc.pyo|134)
[6] [Nov 28 14:34:47] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:34:52] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x0315D4B8> started processing   (Worker.pyo|251)
[6] [Nov 28 14:34:52] [ control server                ] Reusing session for client '127.0.0.1', application 'opsiclientd_event_starter.exe'   (Worker.pyo|397)
[5] [Nov 28 14:34:52] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsiclientd_event_starter.exe)   (ControlServer.pyo|162)
[5] [Nov 28 14:34:52] [ opsiclientd                   ] -----> Executing: isEventRunning(u'on_shutdown')   (JsonRpc.pyo|134)
[6] [Nov 28 14:34:52] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:34:58] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x03161B98> started processing   (Worker.pyo|251)
[6] [Nov 28 14:34:58] [ control server                ] Reusing session for client '127.0.0.1', application 'opsiclientd_event_starter.exe'   (Worker.pyo|397)
[5] [Nov 28 14:34:58] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsiclientd_event_starter.exe)   (ControlServer.pyo|162)
[5] [Nov 28 14:34:58] [ opsiclientd                   ] -----> Executing: isEventRunning(u'on_shutdown')   (JsonRpc.pyo|134)
[6] [Nov 28 14:34:58] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:35:03] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x03161F58> started processing   (Worker.pyo|251)
[6] [Nov 28 14:35:03] [ control server                ] Reusing session for client '127.0.0.1', application 'opsiclientd_event_starter.exe'   (Worker.pyo|397)
[5] [Nov 28 14:35:03] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsiclientd_event_starter.exe)   (ControlServer.pyo|162)
[5] [Nov 28 14:35:03] [ opsiclientd                   ] -----> Executing: isEventRunning(u'on_shutdown')   (JsonRpc.pyo|134)
[6] [Nov 28 14:35:03] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:35:08] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x03161B98> started processing   (Worker.pyo|251)
[6] [Nov 28 14:35:08] [ control server                ] Reusing session for client '127.0.0.1', application 'opsiclientd_event_starter.exe'   (Worker.pyo|397)
[5] [Nov 28 14:35:08] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsiclientd_event_starter.exe)   (ControlServer.pyo|162)
[5] [Nov 28 14:35:08] [ opsiclientd                   ] -----> Executing: isEventRunning(u'on_shutdown')   (JsonRpc.pyo|134)
[6] [Nov 28 14:35:08] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:35:13] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x031619B8> started processing   (Worker.pyo|251)
[6] [Nov 28 14:35:13] [ control server                ] Reusing session for client '127.0.0.1', application 'opsiclientd_event_starter.exe'   (Worker.pyo|397)
[5] [Nov 28 14:35:13] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsiclientd_event_starter.exe)   (ControlServer.pyo|162)
[5] [Nov 28 14:35:13] [ opsiclientd                   ] -----> Executing: isEventRunning(u'on_shutdown')   (JsonRpc.pyo|134)
[6] [Nov 28 14:35:13] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:35:18] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x03161058> started processing   (Worker.pyo|251)
[6] [Nov 28 14:35:18] [ control server                ] Reusing session for client '127.0.0.1', application 'opsiclientd_event_starter.exe'   (Worker.pyo|397)
[5] [Nov 28 14:35:18] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsiclientd_event_starter.exe)   (ControlServer.pyo|162)
[5] [Nov 28 14:35:18] [ opsiclientd                   ] -----> Executing: isEventRunning(u'on_shutdown')   (JsonRpc.pyo|134)
[6] [Nov 28 14:35:18] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:35:24] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x031617D8> started processing   (Worker.pyo|251)
[5] [Nov 28 14:35:24] [ control server                ] New session created   (Session.pyo|184)
[5] [Nov 28 14:35:24] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsiclientd_event_starter.exe)   (ControlServer.pyo|162)
[5] [Nov 28 14:35:24] [ opsiclientd                   ] -----> Executing: backend_info()   (JsonRpc.pyo|134)
[6] [Nov 28 14:35:24] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[6] [Nov 28 14:35:24] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x03161A30> started processing   (Worker.pyo|251)
[6] [Nov 28 14:35:24] [ control server                ] Reusing session for client '127.0.0.1', application 'opsiclientd_event_starter.exe'   (Worker.pyo|397)
[5] [Nov 28 14:35:24] [ control server                ] Authorization request from UrlVomClient@127.0.0.1 (application: opsiclientd_event_starter.exe)   (ControlServer.pyo|162)
[5] [Nov 28 14:35:24] [ opsiclientd                   ] -----> Executing: isInstallationPending()   (JsonRpc.pyo|134)
[6] [Nov 28 14:35:24] [ opsiclientd                   ] Got result   (JsonRpc.pyo|142)
[5] [Nov 28 14:35:42] [ opsiclientd                   ] Someone triggered a reboot or a shutdown => clearing reboot request   (Opsiclientd.pyo|484)
[5] [Nov 28 14:35:43] [ opsiclientd                   ] opsiclientd is going down   (Opsiclientd.pyo|329)
[6] [Nov 28 14:35:43] [ opsiclientd                   ] Stopping event generator <CustomEventGenerator on_demand>   (Opsiclientd.pyo|332)
[6] [Nov 28 14:35:43] [ event generator on_demand     ] Event generator '<CustomEventGenerator on_demand>' now deactivated after 1 event occurrences   (Events.pyo|489)
[6] [Nov 28 14:35:43] [ event generator on_demand     ] Need to import wmi / pythoncom   (Windows.pyo|60)
[6] [Nov 28 14:35:45] [ opsiclientd                   ] Stopping event generator <GUIStartupEventGenerator gui_startup>   (Opsiclientd.pyo|332)
[6] [Nov 28 14:35:48] [ opsiclientd                   ] Stopping event generator <CustomEventGenerator silent_install>   (Opsiclientd.pyo|332)
[6] [Nov 28 14:35:48] [ event generator silent_install] Event generator '<CustomEventGenerator silent_install>' now deactivated after 1 event occurrences   (Events.pyo|489)
[4] [Nov 28 14:35:48] [ event generator on_demand     ] Failed to import: (-2147023781, 'Der Computer wird heruntergefahren.', None, None), retrying in 2 seconds   (Windows.pyo|75)
[6] [Nov 28 14:35:48] [ event generator silent_install] Need to import wmi / pythoncom   (Windows.pyo|60)
[6] [Nov 28 14:35:50] [ opsiclientd                   ] Stopping event generator <CustomEventGenerator on_shutdown>   (Opsiclientd.pyo|332)
[6] [Nov 28 14:35:50] [ event generator on_shutdown   ] Event generator '<CustomEventGenerator on_shutdown>' now deactivated after 1 event occurrences   (Events.pyo|489)
[6] [Nov 28 14:35:50] [ event generator on_shutdown   ] Need to import wmi / pythoncom   (Windows.pyo|60)
[4] [Nov 28 14:35:50] [ event generator on_demand     ] Failed to import: (-2147221020, 'Ung\xfcltige Syntax', None, None), retrying in 2 seconds   (Windows.pyo|75)
[6] [Nov 28 14:35:52] [ opsiclientd                   ] Stopping event generator <SyncCompletedEventGenerator sync_completed>   (Opsiclientd.pyo|332)
[6] [Nov 28 14:35:52] [ event generator sync_completed] Event generator '<SyncCompletedEventGenerator sync_completed>' now deactivated after 1 event occurrences   (Events.pyo|489)
[6] [Nov 28 14:35:52] [ event generator sync_completed] Event generator '<SyncCompletedEventGenerator sync_completed>' exiting    (Events.pyo|500)
[6] [Nov 28 14:35:52] [ opsiclientd                   ] Stopping event generator <SwOnDemandEventGenerator software_on_demand>   (Opsiclientd.pyo|332)
[6] [Nov 28 14:35:52] [ event generator software_on_demand] Event generator '<SwOnDemandEventGenerator software_on_demand>' now deactivated after 1 event occurrences   (Events.pyo|489)
[6] [Nov 28 14:35:52] [ event generator software_on_demand] Event generator '<SwOnDemandEventGenerator software_on_demand>' exiting    (Events.pyo|500)
[6] [Nov 28 14:35:52] [ opsiclientd                   ] Stopping event generator <PanicEventGenerator panic>   (Opsiclientd.pyo|332)
[6] [Nov 28 14:35:52] [ event generator panic         ] Event generator '<PanicEventGenerator panic>' now deactivated after 1 event occurrences   (Events.pyo|489)
[6] [Nov 28 14:35:52] [ event generator panic         ] Event generator '<PanicEventGenerator panic>' exiting    (Events.pyo|500)
[6] [Nov 28 14:35:52] [ opsiclientd                   ] Waiting for event processing thread <EventProcessingThread(Thread-56, started daemon 1376)>   (Opsiclientd.pyo|337)
[4] [Nov 28 14:35:52] [ event generator on_demand     ] Failed to import: (-2147221020, 'Ung\xfcltige Syntax', None, None), retrying in 2 seconds   (Windows.pyo|75)
[4] [Nov 28 14:35:54] [ event generator on_demand     ] Failed to import: (-2147221020, 'Ung\xfcltige Syntax', None, None), retrying in 2 seconds   (Windows.pyo|75)
[4] [Nov 28 14:35:56] [ event generator on_demand     ] Failed to import: (-2147221020, 'Ung\xfcltige Syntax', None, None), retrying in 2 seconds   (Windows.pyo|75)
[6] [Nov 28 14:35:57] [ opsiclientd                   ] Stopping cache service   (Opsiclientd.pyo|340)
[6] [Nov 28 14:35:57] [ opsiclientd                   ] Stopping control server   (Opsiclientd.pyo|345)
[6] [Nov 28 14:35:57] [ opsiclientd                   ] Stopping control pipe   (Opsiclientd.pyo|350)
[5] [Nov 28 14:35:57] [ opsiclientd                   ] opsiclientd stopped   (Windows.pyo|270)
[5] [Nov 28 14:35:57] [ opsiclientd                   ] Running thread after stop: <Thread(PoolThread-twisted.internet.reactor-0, started daemon 3200)>   (Windows.pyo|272)
[5] [Nov 28 14:35:57] [ opsiclientd                   ] Running thread after stop: <CustomEventGenerator silent_install>   (Windows.pyo|272)
[5] [Nov 28 14:35:57] [ opsiclientd                   ] Running thread after stop: <CustomEventGenerator on_shutdown>   (Windows.pyo|272)
[5] [Nov 28 14:35:57] [ opsiclientd                   ] Running thread after stop: <OpsiclientdNT61(Thread-1, started daemon 564)>   (Windows.pyo|272)
[5] [Nov 28 14:35:57] [ opsiclientd                   ] Running thread after stop: <ReactorThread(Thread-3, started daemon 1208)>   (Windows.pyo|272)
[5] [Nov 28 14:35:57] [ opsiclientd                   ] Running thread after stop: <_DummyThread(Dummy-2, started daemon 1460)>   (Windows.pyo|272)
[5] [Nov 28 14:35:57] [ opsiclientd                   ] Running thread after stop: <_Timer(Thread-86, started daemon 3264)>   (Windows.pyo|272)
[5] [Nov 28 14:35:57] [ opsiclientd                   ] Running thread after stop: <FireEventThread(Thread-55, started daemon 1096)>   (Windows.pyo|272)
[5] [Nov 28 14:35:57] [ opsiclientd                   ] Running thread after stop: <NTControlPipe(Thread-5, started daemon 2896)>   (Windows.pyo|272)
[5] [Nov 28 14:35:57] [ opsiclientd                   ] Running thread after stop: <_Timer(Thread-96, started daemon 760)>   (Windows.pyo|272)
[5] [Nov 28 14:35:57] [ opsiclientd                   ] Running thread after stop: <_Timer(Thread-99, started daemon 3284)>   (Windows.pyo|272)
[5] [Nov 28 14:35:57] [ opsiclientd                   ] Running thread after stop: <EventProcessingThread(Thread-56, started daemon 1376)>   (Windows.pyo|272)
[5] [Nov 28 14:35:57] [ opsiclientd                   ] Running thread after stop: <_MainThread(MainThread, started 2024)>   (Windows.pyo|272)
[5] [Nov 28 14:35:57] [ opsiclientd                   ] Running thread after stop: <_Timer(Thread-79, started daemon 1644)>   (Windows.pyo|272)
[5] [Nov 28 14:35:57] [ opsiclientd                   ] Running thread after stop: <CustomEventGenerator on_demand>   (Windows.pyo|272)
[5] [Nov 28 14:35:57] [ opsiclientd                   ] Running thread after stop: <_Timer(Thread-62, started daemon 1020)>   (Windows.pyo|272)

Code: Alles auswählen

root@opsi:~# opsi-package-manager -l | grep opsi
   l-opsi-server                       4.0.7.1-3                 Installs opsi  
   opsi-adminutils                     4.0.3-1                   some administration tools (not only) for opsi 
   opsi-client-agent                   4.0.7.10-1                opsi.org client agent 
   opsi-winst                          4.11.6.8-1                winst 
   opsi-winst-test                     4.11.6.4-1                opsi-winst test  

Code: Alles auswählen

root@opsi:~# dpkg -l |grep opsi
ii  opsi-depotserver                 4.0.6.7-2                     all          opsi depotserver configuration package
ii  opsi-linux-bootimage             20160921-1                    amd64        opsi bootimage for netboot tasks.
ii  opsi-utils                       4.0.7.7-1                     all          utilites for working with opsi.
ii  opsiconfd                        4.0.7.4-1                     all          opsi configuration service
ii  opsipxeconfd                     4.0.7.1-1                     all          opsi pxe configuration daemon
ii  python-opsi                      4.0.7.26-1                    all          opsi python library
damien.leviet
Beiträge: 110
Registriert: 24 Feb 2014, 11:30

Re: Problem bei Shutdown-Installation

Beitrag von damien.leviet »

Ist bei mir genauso!

Da ist wohl etwas verändert worden seit der letzten Version :?

Hilfe!
andré
Beiträge: 324
Registriert: 07 Jan 2014, 10:48

Re: Problem bei Shutdown-Installation

Beitrag von andré »

Hat außer Damien und mir keiner das Problem und vielleicht sogar eine Lösung?
andré
Beiträge: 324
Registriert: 07 Jan 2014, 10:48

Re: Problem bei Shutdown-Installation

Beitrag von andré »

Ich habe noch zwei Rechner mit der älteren client-agent-Version 4.0.7.7-4 gehabt, mit denen ich testen konnte. Ich habe dazu erstmal mit den Windows-Patchständen September bzw Oktober und dem aktuellen von Ende November getestet, für den Fall, dass irgendein Windowspatch das Problem verursacht.

Das Problem trat aber in beiden Fällen erst auf, wenn die aktuelle client-agent-Version 4.0.7.10-1 installiert worden ist.

Ich gehe daher davon aus, dass es irgendwo beim client-agent ein Problem geben muss. Ich habe die Properties "on_shutdown_install" und "on_shutdown_install_set_policy" beide auf "on" gesetzt.
andré
Beiträge: 324
Registriert: 07 Jan 2014, 10:48

Re: Problem bei Shutdown-Installation

Beitrag von andré »

Woran ich natürlich überhaupt nicht gedacht habe, war einfach noch einmal in das Changelog vom opsi-client-agent zu schauen. Dadurch kam ich auf die Ursache des Problems, nämlich den opsiclientd_event_starter, der in Version 4.0.7.9-1 den opsiclientd_shutdown_starter abgelöst hat. Wenn ich in den entsprechenden doinstall*.cmd-Dateien unter C:\Program Files (x86)\opsi.org\opsi-client-agent\on_shutdown\ den Aufruf auf den opsiclientd_event_starter durch den älteren opsiclientd_shutdown_starter ersetze, funktioniert die Installation beim Herunterfahren wieder, da ist also irgendwo der Wurm drin.
Antworten