Error: retrieveJSONObject --- opsi service problem
Verfasst: 22 Jun 2017, 00:01
After migration to a new server a few of my clients did not work any more. The opsi client started, and sent the log file to the server.
opsi-script.log
opsiclientd.log
After this it just stopped, well, a few lines until the end.
I fixed it by removing all mysql entries from /etc/opsi/backendManager/dispatch.conf, and then the installation went through. Adding the mysql entries back again afterwards made all hardware information available again, and the client still worked. I'm not sure why this works.
Of course I tried everything I knew, --init-current-config, --cleanup-backend, --update-mysql, --set-rights, etc etc. I removed the client, and created a new one, copied the new PCkey to the client. I also reinstalled the opsi-client-agent, all to no avail.
Is the mysql database checked for inconsistencies during the --cleanup-backend phase?
opsi-script.log
Code: Alles auswählen
[1] [Jun 21 23:41:51:408] opsi-script 4.11.6.12 started at >>
[1] [Jun 21 23:41:51:408] opsi-script log file with encoding utf8
[1] [Jun 21 23:41:51:408] startmessage opsi-script created at CentralForm.FormCreate: 21-06-2017 23:41:51
[1] [Jun 21 23:41:51:408] Loading skin from: C:\Program Files (x86)\opsi.org\opsi-client-agent\opsi-winst\winstskin
[1] [Jun 21 23:41:51:408] Depot path from readconfig: p:\ 21-06-2017 23:41:51
[1] [Jun 21 23:41:51:408] startmessage StartProgramModes and create log: 21-06-2017 23:41:51
[1] [Jun 21 23:41:51:408] pm: 5 21-06-2017 23:41:51
[1] [Jun 21 23:41:51:408] startmessage start opsi service connection: 21-06-2017 23:41:51
[1] [Jun 21 23:41:51:408] startmessage: opsidata initialized: 21-06-2017 23:41:51
[1] [Jun 21 23:41:51:408] startmessage create log: 21-06-2017 23:41:51
[6] [Jun 21 23:41:51:408] JSON Bench for getDepotId "params":["client.domain.local"],"id" Start: 23:41:51:408 Time: 00:00:00:000
[3] [Jun 21 23:41:51:409] Error: retrieveJSONObject --- opsi service problem ----> unexpected Result from webservice in retrieveJSONObject, number of lines: 0-> retrieveJSONObject:1: Stream read error
[6] [Jun 21 23:41:51:409] Starting sorting POC
[6] [Jun 21 23:41:51:409] JSON Bench for getProductOrdering "params":["JSON connection not established"],"id": Start: 23:41:51:409 Time: 00:00:00:000
[3] [Jun 21 23:41:51:409] Error: retrieveJSONObject --- opsi service problem ----> unexpected Result from webservice in retrieveJSONObject, number of lines: 0-> retrieveJSONObject:1: Stream read error
[3] [Jun 21 23:41:51:409] Failed fetching sorted POC list !
[3] [Jun 21 23:41:51:409] No correct calculated installation sequence !
[6] [Jun 21 23:41:51:409] Starting fetching unsorted POC list
[6] [Jun 21 23:41:51:409] JSON Bench for backend_setOptions "params":[{"processProductOnClientSequence":true}] Start: 23:41:51:409 Time: 00:00:00:000
[3] [Jun 21 23:41:51:409] Error: retrieveJSONObject --- opsi service problem ----> unexpected Result from webservice in retrieveJSONObject, number of lines: 0-> retrieveJSONObject:1: Stream read error
[4] [Jun 21 23:41:51:409] Product sequence calculated by opsi-script
[5] [Jun 21 23:41:51:409] Computername:client.domain.local
[5] [Jun 21 23:41:51:409] Computername according to Environment Variable :CLIENT
[5] [Jun 21 23:41:51:409] opsi service URL opsi-config.domain.local
[6] [Jun 21 23:41:51:409] Depot path: p:\
[6] [Jun 21 23:41:51:409]
[5] [Jun 21 23:41:51:411] bootmode BKSTD
[6] [Jun 21 23:41:51:411] Registry key [HKLM\SOFTWARE\opsi.org\winst] opened
[6] [Jun 21 23:41:51:411] Variable "RebootRequested" is keeping its value "0"
[6] [Jun 21 23:41:51:411] Variable "LastLogFilename" is keeping its value "c:\opsi.org\log\opsi-script.log"
[6] [Jun 21 23:41:51:411] Variable "ContinueLogFile" is keeping its value "0"
[6] [Jun 21 23:41:51:411] Variable "NumberOfErrors" is keeping its value "0"
[6] [Jun 21 23:41:51:425] Key flushed
[6] [Jun 21 23:41:51:426] Key closed
[5] [Jun 21 23:41:51:428] -------- submitted part of log file ends here, see the rest of log file on client ----------
[5] [Jun 21 23:41:51:428] read file created
[5] [Jun 21 23:41:51:428] read file opend
[5] [Jun 21 23:41:51:428] start reading read file ...
[5] [Jun 21 23:41:51:429] write line: >", "client.domain.local", "false"], "id": 1}< to service...
[5] [Jun 21 23:41:51:429] start sending read file ...
[3] [Jun 21 23:41:51:429] Exception in retrieveJSONObjectByHttpPost: stream handling
[3] [Jun 21 23:41:51:429] Exception in retrieveJSONObjectByHttpPost: stream handling
[6] [Jun 21 23:41:51:429] JSON Bench for backend_exit "params":[],"id":1} Start: 23:41:51:429 Time: 00:00:00:000
[3] [Jun 21 23:41:51:429] Error: retrieveJSONObject --- opsi service problem ----> unexpected Result from webservice in retrieveJSONObject, number of lines: 0-> retrieveJSONObject:1: Stream read error
[3] [Jun 21 23:41:51:429] exception in finishOpsiConf: backend_exit List index (0) out of bounds
[1] [Jun 21 23:41:51:429] ============ opsi-script Version 4.11.6.12 is regularly exiting. Time 2017-06-21 23:41:51 .
Code: Alles auswählen
[7] [Jun 21 23:04:02] [ event config gui_startup ] Parsing ini file 'C:\Program Files (x86)\opsi.org\opsi-client-agent\opsiclientd\opsiclientd.conf' (__init__.pyo|518)
[7] [Jun 21 23:04:02] [ event config gui_startup ] Trying to lock file 'C:\Program Files (x86)\opsi.org\opsi-client-agent\opsiclientd\opsiclientd.conf' (0/2000) (__init__.pyo|216)
[7] [Jun 21 23:04:02] [ event config gui_startup ] File 'C:\Program Files (x86)\opsi.org\opsi-client-agent\opsiclientd\opsiclientd.conf' locked after 0 millis (__init__.pyo|237)
[7] [Jun 21 23:04:02] [ event config gui_startup ] Finished reading file after 0.000 seconds (__init__.pyo|595)
[5] [Jun 21 23:04:02] [ event processing gui_startup{installation_pending}] 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)
[7] [Jun 21 23:04:02] [ event generator wait_for_gui ] messageChanged: subject id 'message', message '' (Message.pyo|488)
[7] [Jun 21 23:04:02] [ event generator wait_for_gui ] sending notification 'messageChanged' to clients (Message.pyo|543)
[5] [Jun 21 23:04:02] [ event processing gui_startup{installation_pending}] Writing log to service (EventProcessing.pyo|257)
[7] [Jun 21 23:04:02] [ event generator wait_for_gui ] messageChanged: subject id 'status', message 'Writing log to service' (Message.pyo|488)
[7] [Jun 21 23:04:02] [ event generator wait_for_gui ] sending notification 'messageChanged' to clients (Message.pyo|543)
[7] [Jun 21 23:04:02] [ event config gui_startup ] Executing jsonrpc method 'backend_exit' on host u'opsi-config.domain.local' (JSONRPC.pyo|115)
[8] [Jun 21 23:04:02] [ event config gui_startup ] jsonrpc: '{"params": [], "id": 18, "method": "backend_exit"}' (JSONRPC.pyo|119)
[7] [Jun 21 23:04:02] [ event config gui_startup ] Posting request... (JSONRPC.pyo|713)
[7] [Jun 21 23:04:02] [ event config gui_startup ] Starting new HTTPS connection (0) to opsi-config.domain.local:4447 (HTTP.pyo|649)
[7] [Jun 21 23:04:02] [ event config gui_startup ] Connection established to: opsi-config.domain.local (HTTP.pyo|651)
[8] [Jun 21 23:04:02] [ event config gui_startup ] Trying to get peer cert... (HTTP.pyo|189)
[8] [Jun 21 23:04:02] [ event config gui_startup ] Failed to get peer cert: 'NoneType' object has no attribute 'getpeercert' (HTTP.pyo|201)
[8] [Jun 21 23:04:02] [ event config gui_startup ] Handing data to connection... (HTTP.pyo|528)
[8] [Jun 21 23:04:02] [ event config gui_startup ] Creating HTTPResponse from httplib... (HTTP.pyo|273)
[7] [Jun 21 23:04:02] [ event config gui_startup ] Closing connection: <httplib.HTTPSConnection instance at 0x02BFF328> (HTTP.pyo|569)
[8] [Jun 21 23:04:02] [ event config gui_startup ] Processing response... (JSONRPC.pyo|719)
[7] [Jun 21 23:04:02] [ event config gui_startup ] Content-Type: gzip-application/json;charset=utf-8, Content-Encoding: deflate (JSONRPC.pyo|730)
[7] [Jun 21 23:04:02] [ event config gui_startup ] Expecting deflated data from server (backwards compatible) (JSONRPC.pyo|738)
[8] [Jun 21 23:04:02] [ event config gui_startup ] Response is: {"id": 18, "result": null, "error": null} (JSONRPC.pyo|750)
I fixed it by removing all mysql entries from /etc/opsi/backendManager/dispatch.conf, and then the installation went through. Adding the mysql entries back again afterwards made all hardware information available again, and the client still worked. I'm not sure why this works.
Of course I tried everything I knew, --init-current-config, --cleanup-backend, --update-mysql, --set-rights, etc etc. I removed the client, and created a new one, copied the new PCkey to the client. I also reinstalled the opsi-client-agent, all to no avail.
Is the mysql database checked for inconsistencies during the --cleanup-backend phase?