'NoneType' object is not iterable when Glance cannot find image data in its backend (e.g. Swift)

[Dmitry Tantsur]

2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager [req-29e934a7-ba1a-4d1b-a622-c39f36c1bc3b 63c009a5db504aff855e56e45540f913 7701a9fe2a7e4cc98a9105bbe0ed2ae9 - default default] Error while preparing t
o deploy to node e78a5e78-9635-436f-ac17-6748f7cd22b8: 'NoneType' object is not iterable: TypeError: 'NoneType' object is not iterable
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager Traceback (most recent call last):
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/conductor/manager.py", line 2842, in do_node_deploy
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager task.driver.deploy.prepare(task)
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic_lib/metrics.py", line 61, in wrapped
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager result = f(*args, **kwargs)
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py", line 148, in wrapper
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager return f(*args, **kwargs)
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/drivers/modules/iscsi_deploy.py", line 539, in prepare
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager task.driver.boot.prepare_ramdisk(task, deploy_opts)
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic_lib/metrics.py", line 61, in wrapped
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager result = f(*args, **kwargs)
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/drivers/modules/pxe.py", line 509, in prepare_ramdisk
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager _cache_ramdisk_kernel(task.context, node, pxe_info)
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/drivers/modules/pxe.py", line 364, in _cache_ramdisk_kernel
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager CONF.force_raw_images)
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/drivers/modules/deploy_utils.py", line 487, in fetch_images
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager cache.fetch_image(href, path, ctx=ctx, force_raw=force_raw)
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/drivers/modules/image_cache.py", line 134, in fetch_image
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager href, master_path, dest_path, ctx=ctx, force_raw=force_raw)
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/drivers/modules/image_cache.py", line 158, in _download_image
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager _fetch(ctx, href, tmp_path, force_raw)
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/drivers/modules/image_cache.py", line 301, in _fetch
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager images.fetch(context, image_href, path_tmp, force_raw=False)
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/common/images.py", line 325, in fetch
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager image_service.download(image_href, image_file)
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/common/glance_service/v2/image_service.py", line 51, in download
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager return self._download(image_id, method='data', data=data)
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/common/glance_service/base_image_service.py", line 73, in wrapper
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager return func(self, *args, **kwargs)
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/common/glance_service/base_image_service.py", line 176, in _download
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager for chunk in image_chunks:
2018-01-04 10:03:40.179 22592 ERROR ironic.conductor.manager TypeError: 'NoneType' object is not iterable

Note that I had to enable tracebacks manually, otherwise I only saw "NoneType object is not iterable" without any details.

UPD: it turns out that Glance returns None as data when the backing storage (e.g. Swift) cannot find data. We need to account for it, if it's valid behavior.

[OpenStack Infra (hudson-openstack)]

Related fix proposed to branch: master
Review: https://review.openstack.org/531120

[Dmitry Tantsur (divius)]

glanceclient has the same problem:

$ openstack image save 67fba704-a2f2-4cb4-a681-f12ff7674b74
Traceback (most recent call last): │····················
  File "/usr/lib/python2.7/site-packages/osc_lib/shell.py", line 134, in run │····················
    ret_val = super(OpenStackShell, self).run(argv) │····················
  File "/usr/lib/python2.7/site-packages/cliff/app.py", line 279, in run │····················
    result = self.run_subcommand(remainder) │····················
  File "/usr/lib/python2.7/site-packages/osc_lib/shell.py", line 169, in run_subcommand │····················
    ret_value = super(OpenStackShell, self).run_subcommand(argv) │····················
  File "/usr/lib/python2.7/site-packages/cliff/app.py", line 400, in run_subcommand │····················
    result = cmd.run(parsed_args) │····················
  File "/usr/lib/python2.7/site-packages/osc_lib/command/command.py", line 41, in run │····················
    return super(Command, self).run(parsed_args) │····················
  File "/usr/lib/python2.7/site-packages/cliff/command.py", line 137, in run │····················
    return_code = self.take_action(parsed_args) or 0 │····················
  File "/usr/lib/python2.7/site-packages/openstackclient/image/v2/image.py", line 652, in take_action │····················
    gc_utils.save_image(data, parsed_args.file) ...

[Dmitry Tantsur (divius)]

Glance logs:

2018-01-04 10:21:35.253 23259 INFO swiftclient [req-88d70259-6494-4c0e-bdeb-830b58bad844 4fa7132784d34526b7b8d3da97009648 e5f6826a39af4cafb2ede235b66cef5e - default default] REQ: curl -i http://10.37.168.1:8080/
v1/AUTH_7701a9fe2a7e4cc98a9105bbe0ed2ae9/glance/67fba704-a2f2-4cb4-a681-f12ff7674b74 -X GET -H "X-Auth-Token: gAAAAABaTgAvzwIE..."
2018-01-04 10:21:35.254 23259 INFO swiftclient [req-88d70259-6494-4c0e-bdeb-830b58bad844 4fa7132784d34526b7b8d3da97009648 e5f6826a39af4cafb2ede235b66cef5e - default default] RESP STATUS: 404 Not Found
2018-01-04 10:21:35.254 23259 INFO swiftclient [req-88d70259-6494-4c0e-bdeb-830b58bad844 4fa7132784d34526b7b8d3da97009648 e5f6826a39af4cafb2ede235b66cef5e - default default] RESP HEADERS: {u'Date': u'Thu, 04 Jan
 2018 10:21:35 GMT', u'Content-Length': u'70', u'Content-Type': u'text/html; charset=UTF-8', u'X-Openstack-Request-Id': u'txbf82d7f756ea4478917db-005a4e002f', u'X-Trans-Id': u'txbf82d7f756ea4478917db-005a4e002f'
}
2018-01-04 10:21:35.254 23259 INFO swiftclient [req-88d70259-6494-4c0e-bdeb-830b58bad844 4fa7132784d34526b7b8d3da97009648 e5f6826a39af4cafb2ede235b66cef5e - default default] RESP BODY: <html><h1>Not Found</h1><p
>The resource could not be found.</p></html>
2018-01-04 10:21:35.255 23259 WARNING glance_store._drivers.swift.store [req-88d70259-6494-4c0e-bdeb-830b58bad844 4fa7132784d34526b7b8d3da97009648 e5f6826a39af4cafb2ede235b66cef5e - default default] Swift could
not find object 67fba704-a2f2-4cb4-a681-f12ff7674b74.: ClientException: Object GET failed: http://10.37.168.1:8080/v1/AUTH_7701a9fe2a7e4cc98a9105bbe0ed2ae9/glance/67fba704-a2f2-4cb4-a681-f12ff7674b74 404 Not Fou
nd [first 60 chars of response] <html><h1>Not Found</h1><p>The resource could not be found.<
2018-01-04 10:21:35.255 23259 WARNING glance.location [req-88d70259-6494-4c0e-bdeb-830b58bad844 4fa7132784d34526b7b8d3da97009648 e5f6826a39af4cafb2ede235b66cef5e - default default] Get image 67fba704-a2f2-4cb4-a
681-f12ff7674b74 data failed: Swift could not find object 67fba704-a2f2-4cb4-a681-f12ff7674b74..: NotFound: Swift could not find object 67fba704-a2f2-4cb4-a681-f12ff7674b74.
2018-01-04 10:21:35.255 23259 ERROR glance.location [req-88d70259-6494-4c0e-bdeb-830b58bad844 4fa7132784d34526b7b8d3da97009648 e5f6826a39af4cafb2ede235b66cef5e - default default] Glance tried all active locations to get data for image 67fba704-a2f2-4cb4-a681-f12ff7674b74 but all have failed.: NotFound: Swift could not find object 67fba704-a2f2-4cb4-a681-f12ff7674b74.

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/531201
Committed: https://git.openstack.org/cgit/openstack/python-openstackclient/commit/?id=ed1b59848fd2a6b7bed7618ab5ac0db00e8110dc
Submitter: Zuul
Branch: master

commit ed1b59848fd2a6b7bed7618ab5ac0db00e8110dc
Author: Mike Fedosin <email address hidden>
Date: Thu Jan 4 17:49:28 2018 +0100

    Check that Glance returns image data before processing it

    Now if Glance v2 cannot find image data it returns an empty
    response with 204 status code, instead of raising an error.

    Glance client handles this situation and wraps the response
    with a RequestIdProxy object, whose 'wrapped' attribute is
    None.

    But when openstack client tries to parse this object using
    glanceclient's save_image util function, it fails with
    "NoneType object is not iterable" message, for the
    object doesn't contain any data.

    This patch adds additional check to prevent such behaviour
    and raises SystemExit exception if no data was returned from
    the server.

    Glance v1 is not affected, because it raises an error if can't
    find an image data.

    Change-Id: I016a60462ba586f9fa7585c2cfafffd7be38de7b
    Closes-Bug: #1741223

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/python-openstackclient 3.14.0 release.

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/531120
Committed: https://git.openstack.org/cgit/openstack/ironic/commit/?id=2b5849b49e24f310b7cf7f7c2e9a8b14f11da2a7
Submitter: Zuul
Branch: master

commit 2b5849b49e24f310b7cf7f7c2e9a8b14f11da2a7
Author: Dmitry Tantsur <email address hidden>
Date: Thu Jan 4 11:10:18 2018 +0100

    Rework exception handling on deploy failures in conductor

    Currently on unexpected python error we only log the error message, e.g.
    "NoneType object is not iterable" or just KeyError missing key. This is
    obviously not helping debugging too much.

    This change splits error handling into separate handling of IronicException
    and other exceptions.

    For IronicException: only log the error message, remove redundant "Error: "
    from the last_error message.

    For other exceptions: log traceback, mention that the exception was not
    expected.

    Finally, move logging to the top of the error handling helper to make sure
    it never gets lost.

    Change-Id: Idc2339c3bdad8092907d9651d40f241a2ae50dbe
    Related-Bug: #1741223

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/531180
Committed: https://git.openstack.org/cgit/openstack/ironic/commit/?id=70039cbe607195f66872d8640976c13284f75b79
Submitter: Zuul
Branch: master

commit 70039cbe607195f66872d8640976c13284f75b79
Author: Dmitry Tantsur <email address hidden>
Date: Thu Jan 4 16:47:20 2018 +0100

    Handle case when a glance image contains no data

    In my experience, it happens when Swift storage backing Glance was
    purged, but it can probably also happen if an image never had data
    at all. This patch raises a correct exception instead of TypeError.

    Switch relevant unit tests to Glance V2, as V1 is long deprecated.

    Change-Id: I75e5ae7f46ce3a1506ed6108ff05df3083fd5084
    Closes-Bug: #1741223

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/ironic 10.1.0 release.

[OpenStack Infra (hudson-openstack)]

Related fix proposed to branch: stable/queens
Review: https://review.openstack.org/545807

[OpenStack Infra (hudson-openstack)]

Change abandoned by Dmitry Tantsur (<email address hidden>) on branch: stable/queens
Review: https://review.openstack.org/545807
Reason: Invalid backport