Requested products are not installed

Antworten
realflash
Beiträge: 13
Registriert: 14 Aug 2014, 17:48

Requested products are not installed

Beitrag von realflash »

Dear all,

Having tested a single server OPSI instance successfully, I have built a second instance with two servers; one config server and one depot server. I have joined my first client (d002) to the config server (10.200.2.7) and set the requested status of three packages that are not installed to 'setup'. When I send on_demand to d002, opsiclientd responds as expected, and launches opsi-winst. But opsi-winst makes no attempt to install the packages:

Code: Alles auswählen

[1] [Jan 21 15:19:26:673] opsi-winst 4.11.4.12 started at >>
[1] [Jan 21 15:19:26:673] startmessage opsi-winst created at CentralForm.FormCreate: 21/01/2015 15:19:25
[1] [Jan 21 15:19:26:673] Loading skin from: C:\Program Files\opsi.org\opsi-client-agent\opsi-winst\winstskin
[1] [Jan 21 15:19:26:673] startmessage StartProgramModes and create log: 21/01/2015 15:19:25
[1] [Jan 21 15:19:26:673] startmessage start opsi service connection: 21/01/2015 15:19:25
[1] [Jan 21 15:19:26:673] JSON Bench for backend_info "params":[],"id":1} Start: 15:19:25:533 Time: 00:00:01:137
[1] [Jan 21 15:19:26:673] startmessage create log: 21/01/2015 15:19:26
[6] [Jan 21 15:19:26:674] JSON service request https://10.200.2.7:4447/rpc getDepotId
[6] [Jan 21 15:19:26:837] JSON Bench for getDepotId "params":["d002.c1.prod.amiab.int"],"id":1} Start: 15:19:26:674 Time: 00:00:00:163
[6] [Jan 21 15:19:26:841] JSON service request https://10.200.2.7:4447/rpc backend_setOptions
[6] [Jan 21 15:19:26:959] JSON Bench for backend_setOptions "params":[{"processProductOnClientSequence":true}] Start: 15:19:26:841 Time: 00:00:00:118
[6] [Jan 21 15:19:26:963] JSON service request https://10.200.2.7:4447/rpc productOnClient_getObjects
[6] [Jan 21 15:19:27:188] JSON Bench for productOnClient_getObjects "params":["",{"clientId":"d002.c1.prod.amiab.int", Start: 15:19:26:963 Time: 00:00:00:225
[6] [Jan 21 15:19:27:192] JSON service request https://10.200.2.7:4447/rpc backend_setOptions
[6] [Jan 21 15:19:27:308] JSON Bench for backend_setOptions "params":[{"processProductOnClientSequence":false} Start: 15:19:27:192 Time: 00:00:00:116
[5] [Jan 21 15:19:27:312] Computername:d002.c1.prod.amiab.int
[5] [Jan 21 15:19:27:312] Computername according to Environment Variable :D002
[5] [Jan 21 15:19:27:312] opsi service URL https://10.200.2.7:4447
[5] [Jan 21 15:19:27:312] Depot path:  p:\
[5] [Jan 21 15:19:27:312] 
[5] [Jan 21 15:19:27:312] bootmode BKSTD
???SHOULD BE SOMETHING HAPPENING IN HERE???
[6] [Jan 21 15:19:27:312] Registry key [HKLM\SOFTWARE\opsi.org\winst]  opened
[6] [Jan 21 15:19:27:312]                 Variable "RebootRequested"  set to "0"
[6] [Jan 21 15:19:27:313]                 Variable "LastLogFilename"  had value  "c:\tmp\opsi-client-agent.log"
[6] [Jan 21 15:19:27:313]                 Info:    "LastLogFilename"  changed to "c:\opsi.org\log\opsi-script.log"
[6] [Jan 21 15:19:27:313]                 Variable "ContinueLogFile"  had value  "1"
[6] [Jan 21 15:19:27:313]                 Info:    "ContinueLogFile"  changed to "0"
[6] [Jan 21 15:19:27:313]                 Variable "NumberOfErrors"  not found. Code: 2
[6] [Jan 21 15:19:27:322]                 Key flushed
[6] [Jan 21 15:19:27:322]                 Key closed
[5] [Jan 21 15:19:27:322] -------- submitted part of log file ends here, see the rest of log file on client ----------
[5] [Jan 21 15:19:27:323] read file created
[5] [Jan 21 15:19:27:323] read file opend
[5] [Jan 21 15:19:27:323] start reading read file ...
[5] [Jan 21 15:19:27:324] write line: >", "d002.c1.prod.amiab.int", "false"], "id": 1}<  to service...
[5] [Jan 21 15:19:27:324] start sending read file ...
[6] [Jan 21 15:19:27:516] JSON service request https://10.200.2.7:4447/rpc backend_exit
[6] [Jan 21 15:19:27:645] JSON Bench for backend_exit "params":[],"id":1} Start: 15:19:27:516 Time: 00:00:00:129
I know the product are requested because if I call "getProductStates_hash", I get this:

Code: Alles auswählen

{"id": 1,

"result": {"d002.c1.prod.amiab.int": [{"lastStateChange": "20150121080506",

"actionRequest": "setup",

"productVersion": "",

"productActionProgress": "",

"packageVersion": "",

"installationStatus": "not_installed",

"productId": "adobeflashplayer"},

{"lastStateChange": "20150121075327",

"actionRequest": "none",

"productVersion": "4.0.5.2",

"productActionProgress": "",

"packageVersion": "2",

"installationStatus": "installed",

"productId": "opsi-client-agent"},

{"lastStateChange": "20150121110159",

"actionRequest": "setup",

"productVersion": "",

"productActionProgress": "",

"packageVersion": "",

"installationStatus": "not_installed",

"productId": "jre"},

{"lastStateChange": "20150121110159",

"actionRequest": "setup",

"productVersion": "",

"productActionProgress": "",

"packageVersion": "",

"installationStatus": "not_installed",

"productId": "adobereader"}]},

"error": null}
Please can anyone tell me why opsi-winst is not attempting to install the products?

opsiconfd-4.0.5.2-1.2
opsi-client-agent-4.0.5.2-2
realflash
Beiträge: 13
Registriert: 14 Aug 2014, 17:48

Re: Requested products are not installed

Beitrag von realflash »

Update - version of opsi-winst is 4.11.4.12, I believe.
Benutzeravatar
n.wenselowski
Ex-uib-Team
Beiträge: 3194
Registriert: 04 Apr 2013, 12:15

Re: Requested products are not installed

Beitrag von n.wenselowski »

Hello,

this is very strange. Did you try to restart your Client and then try it again?


~Niko

Code: Alles auswählen

import OPSI
realflash
Beiträge: 13
Registriert: 14 Aug 2014, 17:48

Re: Requested products are not installed

Beitrag von realflash »

I have tried that, yes. Looking into the code for opsi-winst, it looks like Produkt.Count is probably 0. Is there way I can change the logging level on opsiconfd to log the contents of inbound and outbound messages, so that I can see that it is telling the client?
Benutzeravatar
n.wenselowski
Ex-uib-Team
Beiträge: 3194
Registriert: 04 Apr 2013, 12:15

Re: Requested products are not installed

Beitrag von n.wenselowski »

Hallo,

setting the loglevel in the opsiclientd.conf should do the trick. More information in the manual. (There is a part configuration that should be it's own heading in the future - for now you have to manually search it.)


With kind regards

Niko

Code: Alles auswählen

import OPSI
realflash
Beiträge: 13
Registriert: 14 Aug 2014, 17:48

Re: Requested products are not installed

Beitrag von realflash »

I have looked in the opsiclientd.log on the desktop, and here's the relevant part from when I sent the on_demand event:

I can see at 13:23:35 that there are products to process as expected.

Code: Alles auswählen

[5] [Jan 23 13:23:25] [ event processing on_demand{user_logged_in}]    [ 1] product adobeflashplayer:    setup   (EventProcessing.pyo|632)
[5] [Jan 23 13:23:25] [ event processing on_demand{user_logged_in}]    [ 2] product jre:                 setup   (EventProcessing.pyo|632)
[5] [Jan 23 13:23:25] [ event processing on_demand{user_logged_in}]    [ 3] product adobereader:         setup   (EventProcessing.pyo|632)
The action processor seems to mount the depot OK

Code: Alles auswählen

[6] [Jan 23 13:23:32] [ action_processor_starter.exe  ] <OPSI.Backend.JSONRPC.JSONRPCBackend instance at 0x0198EAF8>: Connected to service   (JSONRPC.pyo|442)
[6] [Jan 23 13:23:32] [ action_processor_starter.exe  ] Impersonating network account 'pcpatch'   (action_processor_starter.py|98)
[5] [Jan 23 13:23:32] [ action_processor_starter.exe  ] Mounting depot share smb://depot1.pshared.prod.amiab.int/opsi_depot   (action_processor_starter.py|103)
[6] [Jan 23 13:23:33] [ control server                ] Worker <ocdlib.ControlServer.WorkerOpsiclientdJsonRpc instance at 0x039566C0> started processing   (Worker.pyo|249)
And it launches opsi-winst OK and it returns with a 0:

Code: Alles auswählen

[5] [Jan 23 13:23:34] [ action_processor_starter.exe  ] Running command '"C:\Program Files\opsi.org\opsi-client-agent\\opsi-winst\\winst32.exe" /opsiservice "https://10.200.2.7:4447/rpc" /clientid d002.c1.prod.amiab.int /username d002.c1.prod.amiab.int /password *** confidential *** ' as user 'pcpatch' on desktop 'default'   (Windows.pyo|1880)
[6] [Jan 23 13:23:34] [ action_processor_starter.exe  ] Process startet, pid: 3816   (Windows.pyo|1884)
[6] [Jan 23 13:23:34] [ action_processor_starter.exe  ] Waiting for process ending: 3816 (timeout: 10800 seconds)   (Windows.pyo|1887)
[5] [Jan 23 13:23:37] [ action_processor_starter.exe  ] Process 3816 ended with exit code 0   (Windows.pyo|1897)
Where should I look next?

Full log: http://pastebin.com/n0SFB45E
realflash
Beiträge: 13
Registriert: 14 Aug 2014, 17:48

Re: Requested products are not installed

Beitrag von realflash »

I've now confirmed that when opsi-winst requests a list of products (productOnClient_getObjects), opsiconfd returns the correct thing. I turned the log level up to 8:

Code: Alles auswählen

[7] [Jan 23 10:15:48] Got productOnClients (Backend.py|2987)
[6] [Jan 23 10:15:48] Got result (JsonRpc.py|133)
[8] [Jan 23 10:15:48] RPC ID 15: [u'adobeflashplayer;LocalbootProduct;d002.c1.prod.amiab.int', u'jre;LocalbootProduct;d002.c1.prod.amiab.int', u'adobereader;LocalbootProduct;d002.c1.prod.amiab.int'] (JsonRpc.py|134)
[7] [Jan 23 10:15:48] Sending compressed (level: 1) data (Worker.py|593)
So the focus is on why opsi-winst is not actioning that list.
Benutzeravatar
d.oertel
uib-Team
Beiträge: 3327
Registriert: 04 Jun 2008, 14:27

Re: Requested products are not installed

Beitrag von d.oertel »

Hi,

I see that the opsiclientd sees the action requests and starts the opsi-script (opsi-winst).
Could you send the complete log of the opsi-winst (opsi-configed tab /log/ instlog) to me
d.oertel(at)uib.de so I may have look what is going wrong.

regards

d.oertel


Vielen Dank für die Nutzung von opsi. Im Forum ist unser Support begrenzt.

Für den professionellen Einsatz und individuelle Beratung empfehlen wir einen Support-Vertrag und eine Schulung.
Gerne informieren wir Sie zu unserem Angebot.

uib GmbH
Telefon: +49 6131 27561 0
E-Mail: sales@uib.de


realflash
Beiträge: 13
Registriert: 14 Aug 2014, 17:48

Re: Requested products are not installed

Beitrag von realflash »

My first post does contain the whole opsi-winst log. Subject to a bit more testing, I have now resolved this, I think, although I'm not sure how it happened.

I definitely did have the packages I was trying to install appearing on configed - you can see that in the clientd log. It seemed to be that winst was getting different instructions from confd than clientd was. Once I had built winst successfully, I noted in the additional debugging I added that opsi-client-agent was listed and not the others; this caused me to go back to configed, where I found the packages were no longer listed. I re-installed all the packages and everything started working. I don't have enough OPSI knowledge yet to understand what went wrong the first time.

Thank you for trying to help.
Benutzeravatar
d.oertel
uib-Team
Beiträge: 3327
Registriert: 04 Jun 2008, 14:27

Re: Requested products are not installed

Beitrag von d.oertel »

Hi,

sorry that I not seen the complete log in your first posting.

Yes - indeed the opsi-winst did not got the information that there was an action request and therefore terminated.
And I also have no idea why (and with out reproduction of the error it will be hard to find).

regards

d,oertel


Vielen Dank für die Nutzung von opsi. Im Forum ist unser Support begrenzt.

Für den professionellen Einsatz und individuelle Beratung empfehlen wir einen Support-Vertrag und eine Schulung.
Gerne informieren wir Sie zu unserem Angebot.

uib GmbH
Telefon: +49 6131 27561 0
E-Mail: sales@uib.de


Antworten