qemu image convert fails in snapshot

[Sean Dague]

Periodically in the gate we see a failure by qemu image convert in snapshot:

2014-04-07 01:31:29.470 29554 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/nova/nova/openstack/common/processutils.py", line 193, in execute
2014-04-07 01:31:29.470 29554 TRACE oslo.messaging.rpc.dispatcher cmd=' '.join(cmd))
2014-04-07 01:31:29.470 29554 TRACE oslo.messaging.rpc.dispatcher ProcessExecutionError: Unexpected error while running command.
2014-04-07 01:31:29.470 29554 TRACE oslo.messaging.rpc.dispatcher Command: qemu-img convert -f qcow2 -O qcow2 /opt/stack/data/nova/instances/4ff6dc10-eac8-41d2-a645-3a0e0ba07c8a/disk /opt/stack/data/nova/instances/snapshots/tmpcVpCxJ/33eb0bb2b49648c69770b47db3211a86
2014-04-07 01:31:29.470 29554 TRACE oslo.messaging.rpc.dispatcher Exit code: 1
2014-04-07 01:31:29.470 29554 TRACE oslo.messaging.rpc.dispatcher Stdout: ''
2014-04-07 01:31:29.470 29554 TRACE oslo.messaging.rpc.dispatcher Stderr: 'qemu-img: error while reading sector 0: Input/output error\n'

qemu-img is very obtuse on what the actual issue is, so it's unclear if this is a corrupt disk, or a totally missing disk.

The user visible face of this is on operations like shelve where the instance will believe that it's still in active state - http://logs.openstack.org/02/85602/1/gate/gate-tempest-dsvm-full/20ed964/console.html#_2014-04-07_01_44_29_309

Even though everything is broken instead.

Logstash query: http://logstash.openstack.org/#eyJzZWFyY2giOiJcInFlbXUtaW1nOiBlcnJvclwiIiwiZmllbGRzIjpbXSwib2Zmc2V0IjowLCJ0aW1lZnJhbWUiOiI2MDQ4MDAiLCJncmFwaG1vZGUiOiJjb3VudCIsInRpbWUiOnsidXNlcl9pbnRlcnZhbCI6MH0sInN0YW1wIjoxMzk2ODc2MTQ4NDc3fQ==

[Sean Dague (sdague)]

Discussing with danpb, qemu image convert is notoriously terrible at error messages. So I don't know that we can really figure out root cause easily

[Kashyap Chamarthy (kashyapc)]

Just a related note, maybe it's worthwhile to add a 'qemu-img check' command to report any inconsistencies in the disk image.

From `qemu-img` man page of the option 'check':

       [. . .]
       check [-f fmt] [--output=ofmt] [-r [leaks | all]] filename
           Perform a consistency check on the disk image filename. The command can output in the format ofmt which is either
            "human" or "json".

           If "-r" is specified, qemu-img tries to repair any inconsistencies found during the check. "-r leaks" repairs only cluster leaks,
           whereas "-r all" fixes all kinds of errors, with a higher risk of choosing the wrong fix or hiding corruption that has already
           occurred.
       [. . .]

[Fam Zheng (famz)]

This is likely something wrong below qemu-img. Is the source image even accessible with other tools, such as 'dd' or 'cat'?

[Kashyap Chamarthy (kashyapc)]

I had a brief chat with Kevin Wolf (QEMU/qcow2 upstream maintainer), posting his comments here:

    - It (the error) means that the source image could be opened successfully, but the very first read failed.
    - Any specific information about the image in question? Like format, size, etc?

[Kashyap Chamarthy (kashyapc)]

Ping.

I don't see this in the last 7 days from logstash for the string "qemu-img: error while reading sector 0: Input/output error":

http://logstash.openstack.org/#eyJzZWFyY2giOiJcInFlbXUtaW1nOiBlcnJvciB3aGlsZSByZWFkaW5nIHNlY3RvciAwOiBJbnB1dC9vdXRwdXQgZXJyb3JcIiIsImZpZWxkcyI6W10sIm9mZnNldCI6MCwidGltZWZyYW1lIjoiNjA0ODAwIiwiZ3JhcGhtb2RlIjoiY291bnQiLCJ0aW1lIjp7InVzZXJfaW50ZXJ2YWwiOjB9LCJzdGFtcCI6MTQwNTU3ODA3OTczNH0=

Probably it "fixed itself"?

[Jordan Pittier (jordan-pittier)]

This just happened today : http://logs.openstack.org/64/106664/1/check/check-tempest-dsvm-full-icehouse/e10a408/logs/screen-n-cpu.txt.gz?level=TRACE#_2014-07-30_05_43_43_335

https://review.openstack.org/#/c/106664/

[Kairat Kushaev (kkushaev)]

Hello guys!
We faced with the same issues today on gates:
2015-02-19 11:26:02.215 5467 ERROR nova.compute.manager [-] [instance: 11e30652-70a9-480a-9b16-9026be2e3592] Instance failed to spawn
2015-02-19 11:26:02.215 5467 TRACE nova.compute.manager [instance: 11e30652-70a9-480a-9b16-9026be2e3592] Traceback (most recent call last):
2015-02-19 11:26:02.215 5467 TRACE nova.compute.manager [instance: 11e30652-70a9-480a-9b16-9026be2e3592] File "/opt/stack/new/nova/nova/compute/manager.py", line 2316, in _build_resources
2015-02-19 11:26:02.215 5467 TRACE nova.compute.manager [instance: 11e30652-70a9-480a-9b16-9026be2e3592] yield resources
2015-02-19 11:26:02.215 5467 TRACE nova.compute.manager [instance: 11e30652-70a9-480a-9b16-9026be2e3592] File "/opt/stack/new/nova/nova/compute/manager.py", line 2186, in _build_and_run_instance
2015-02-19 11:26:02.215 5467 TRACE nova.compute.manager [instance: 11e30652-70a9-480a-9b16-9026be2e3592] flavor=flavor)
2015-02-19 11:26:02.215 5467 TRACE nova.compute.manager [instance: 11e30652-70a9-480a-9b16-9026be2e3592] File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 2358, in spawn
2015-02-19 11:26:02.215 5467 TRACE nova.compute.manager [instance: 11e30652-70a9-480a-9b16-9026be2e3592] admin_pass=admin_password)
2015-02-19 11:26:02.215 5467 TRACE nova.compute.manager [instance: 11e30652-70a9-480a-9b16-9026be2e3592] File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 2762, in _create_image
2015-02-19 11:26:02.215 5467 TRACE nova.compute.manager [instance: 11e30652-70a9-480a-9b16-9026be2e3592] project_id=instance.project_id)
2015-02-19 11:26:02.215 5467 TRACE nova.compute.manager [instance: 11e30652-70a9-480a-9b16-9026be2e3592] File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 230, in cache
2015-02-19 11:26:02.215 5467 TRACE nova.compute.manager [instance: 11e30652-70a9-480a-9b16-9026be2e3592] *args, **kwargs)
2015-02-19 11:26:02.215 5467 TRACE nova.compute.manager [instance: 11e30652-70a9-480a-9b16-9026be2e3592] File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 477, in create_image
2015-02-19 11:26:02.215 5467 TRACE nova.compute.manager [instance: 11e30652-70a9-480a-9b16-9026be2e3592] prepare_template(target=base, max_size=size, *args, **kwargs)
2015-02-19 11:26:02.215 5467 TRACE nova.compute.manager [instance: 11e30652-70a9-480a-9b16-9026be2e3592] File "/usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py", line 431, in inner
2015-02-19 11:26:02.215 5467 TRACE nova.compute.manager [instance: 11e30652-70a9-480a-9b16-9026be2e3592] return f(*args, **kwargs)
2015-02-19 11:26:02.215 5467 TRACE nova.compute.manager [instance: 11e30652-70a9-480a-9b16-9026be2e3592] File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 220, in fetch_func_sync
2015-02-19 11:26:02.215 5467 TRACE nova.compute.manager [instance: 11e30652-70a9-480a-9b16-9026be2e3592] fetch_func(target=target, *args, **kwargs)
2015-02-19 11:26:02.215 5467 TRACE nova.compute.manager [instance: 11e30652-70a9-480a-9b16-9026be2e3592] File "/opt/stack/new/nova/nova/virt/libvirt/utils.py", line 488, in fetch_image
2015-02-19 11:26:02.215 54...

[Richard Jones (rjones-redhat)]

The failing command and error message is:
qemu-img convert -O raw /opt/stack/data/nova/instances/_base/9916110004678060463128e2f14a55ac921f479c.part /opt/stack/data/nova/instances/_base/9916110004678060463128e2f14a55ac921f479c.converted
qemu-img: error while reading sector 941568: Input/output error

This looks to me like the input disk (presumably in qcow2 format) is corrupt.

[Tony Breeds (o-tony)]

I think it's pretty clear that this confirmed.

[Steve Baker (steve-stevebaker)]

Doesn't appear to be heat related

[Markus Zoeller (markus_z) (mzoeller)]

This is an automated cleanup. This bug report has been closed because it
is older than 18 months and there is no open code change to fix this.
After this time it is unlikely that the circumstances which lead to
the observed issue can be reproduced.

If you can reproduce the bug, please:
* reopen the bug report (set to status "New")
* AND add the detailed steps to reproduce the issue (if applicable)
* AND leave a comment "CONFIRMED FOR: <RELEASE_NAME>"
  Only still supported release names are valid (LIBERTY, MITAKA, OCATA, NEWTON).
  Valid example: CONFIRMED FOR: LIBERTY

[Yafei Yu (yu-yafei)]

It seems solved.
Bug:https://bugzilla.redhat.com/show_bug.cgi?id=1254927
fixed:https://access.redhat.com/errata/RHBA-2015:2546