AgentClient throws incomprehensible error message when agent hits internal server error

Bug #1439498 reported by Ramakrishnan G (rameshg87)
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Ironic
Fix Released
Undecided
John L. Villalovos

Bug Description

Ironic talks to agent using REST and agent is supposed to return a valid json in correct cases. However when agent doesn't return a valid json, Iroinc tries to decode it and throws JSONDecodeError instead of a better error message. For example, a stack trace from conductor log looks like this:

2015-04-01 07:49:53.703 ERROR ironic.drivers.modules.agent_base_vendor [-] Asynchronous exception for node ae3d4bcb-e66d-42e9-ac90-87367a786a5a: Node failed to get image for deploy. exception: Expecting value: line 1 column 1 (char 0)
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor Traceback (most recent call last):
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor File "/opt/stack/ironic/ironic/drivers/modules/agent_base_vendor.py", line 233, in heartbeat
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor self.continue_deploy(task, **kwargs)
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor File "/opt/stack/ironic/ironic/conductor/task_manager.py", line 128, in wrapper
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor return f(*args, **kwargs)
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor File "/opt/stack/ironic/ironic/drivers/modules/ilo/deploy.py", line 817, in continue_deploy
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor uuid_dict = iscsi_deploy.do_agent_iscsi_deploy(task, self._client)
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor File "/opt/stack/ironic/ironic/drivers/modules/iscsi_deploy.py", line 365, in do_agent_iscsi_deploy
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor result = agent_client.start_iscsi_target(node, iqn)
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor File "/opt/stack/ironic/ironic/drivers/modules/agent_client.py", line 107, in start_iscsi_target
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor wait=True)
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor File "/opt/stack/ironic/ironic/drivers/modules/agent_client.py", line 76, in _command
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor return response.json()
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor File "/usr/local/lib/python2.7/dist-packages/requests/models.py", line 799, in json
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor return json.loads(self.text, **kwargs)
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor File "/usr/local/lib/python2.7/dist-packages/simplejson/__init__.py", line 505, in loads
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor return _default_decoder.decode(s)
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor File "/usr/local/lib/python2.7/dist-packages/simplejson/decoder.py", line 370, in decode
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor obj, end = self.raw_decode(s)
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor File "/usr/local/lib/python2.7/dist-packages/simplejson/decoder.py", line 400, in raw_decode
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor return self.scan_once(s, idx=_w(s, idx).end())
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor JSONDecodeError: Expecting value: line 1 column 1 (char 0)
2015-04-01 07:49:53.703 TRACE ironic.drivers.modules.agent_base_vendor

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to ironic (master)

Fix proposed to branch: master
Review: https://review.openstack.org/170275

Changed in ironic:
assignee: nobody → John L. Villalovos (happycamp)
status: New → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to ironic (master)

Reviewed: https://review.openstack.org/170275
Committed: https://git.openstack.org/cgit/openstack/ironic/commit/?id=f789e6cc75816a0ed53947b1998c9d4afd347504
Submitter: Jenkins
Branch: master

commit f789e6cc75816a0ed53947b1998c9d4afd347504
Author: John L. Villalovos <email address hidden>
Date: Thu Apr 2 13:37:53 2015 -0700

    Improve error handling when JSON is not returned by agent

    Sometimes the agent is not returning valid JSON in the response. Handle
    it better and record information about the request and the response to
    help with debugging.

    Will now raise an exception similar to this:
    ironic.common.exception.IronicException: Unable to decode response as JSON.
    Request URL: http://127.0.0.1:9999/v1/commands
    Request body: "{"name": "standby.run_image",
                    "params": {"image_info": {"image_id": "test_image"}}}"
    Response: "this is not json"

    Change-Id: I483884ca5727fbaa3120e2f7c2b381a7d7e8be17
    Closes-Bug: 1439498

Changed in ironic:
status: In Progress → Fix Committed
Thierry Carrez (ttx)
Changed in ironic:
milestone: none → kilo-rc1
status: Fix Committed → Fix Released
Thierry Carrez (ttx)
Changed in ironic:
milestone: kilo-rc1 → 2015.1.0
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.