[ovirt-devel] [VDSM] Flaky stoarge test

[Nir Soffer]

Hi all,

This the second time I see this error - please report if you saw this
error in your tests.

The suspicious thing is this line:

21:32:59 2016-11-27 21:30:34,890 DEBUG (MainThread) [root] SUCCESS:
<err> = "can't open device /var/tmp/tmpA0v1m6/vol0.img: Image is not
in qcow2 format\nno file open, try 'help open'\n"; <rc> = 0
(commands:93)

qemu-io command succeeded - but it logs very alerting error...

I think Kevin Wolf would like to see this.

Ala, can you investigate this?

21:32:59 ======================================================================
21:32:59 FAIL: test_commit('1.1', 0, 1, True) (qemuimg_test.TestCommit)
21:32:59 ----------------------------------------------------------------------
21:32:59 Traceback (most recent call last):
21:32:59   File
"/home/jenkins/workspace/vdsm_master_check-patch-fc24-x86_64/vdsm/tests/testlib.py",
line 135, in wrapper
21:32:59     return f(self, *args)
21:32:59   File
"/home/jenkins/workspace/vdsm_master_check-patch-fc24-x86_64/vdsm/tests/qemuimg_test.py",
line 425, in test_commit
21:32:59     self.assertEqual(os.stat(vol).st_blocks, blocks)
21:32:59 AssertionError: 648 != 776
21:32:59 -------------------- >> begin captured logging << --------------------
21:32:59 2016-11-27 21:30:33,960 DEBUG (MainThread) [root]
/usr/bin/taskset --cpu-list 0-15 /usr/bin/qemu-img create -f raw
/var/tmp/tmpA0v1m6/vol0.img 1048576 (cwd None) (commands:69)
21:32:59 2016-11-27 21:30:33,989 DEBUG (MainThread) [root] SUCCESS:
<err> = ''; <rc> = 0 (commands:93)
21:32:59 2016-11-27 21:30:33,990 DEBUG (MainThread) [root]
/usr/bin/taskset --cpu-list 0-15 qemu-io -f raw -c 'write -P 240 0
1024' /var/tmp/tmpA0v1m6/vol0.img (cwd None) (commands:69)
21:32:59 2016-11-27 21:30:34,049 DEBUG (MainThread) [root] SUCCESS:
<err> = ''; <rc> = 0 (commands:93)
21:32:59 2016-11-27 21:30:34,050 DEBUG (MainThread) [root]
/usr/bin/taskset --cpu-list 0-15 /usr/bin/qemu-img create -f qcow2 -o
compat=1.1 -b /var/tmp/tmpA0v1m6/vol0.img /var/tmp/tmpA0v1m6/vol1.img
1048576 (cwd None) (commands:69)
21:32:59 2016-11-27 21:30:34,117 DEBUG (MainThread) [root] SUCCESS:
<err> = ''; <rc> = 0 (commands:93)
21:32:59 2016-11-27 21:30:34,118 DEBUG (MainThread) [root]
/usr/bin/taskset --cpu-list 0-15 qemu-io -f qcow2 -c 'write -P 241
1024 1024' /var/tmp/tmpA0v1m6/vol1.img (cwd None) (commands:69)
21:32:59 2016-11-27 21:30:34,282 DEBUG (MainThread) [root] SUCCESS:
<err> = ''; <rc> = 0 (commands:93)
21:32:59 2016-11-27 21:30:34,282 DEBUG (MainThread) [root]
/usr/bin/taskset --cpu-list 0-15 /usr/bin/qemu-img create -f qcow2 -o
compat=1.1 -b /var/tmp/tmpA0v1m6/vol1.img /var/tmp/tmpA0v1m6/vol2.img
1048576 (cwd None) (commands:69)
21:32:59 2016-11-27 21:30:34,334 DEBUG (MainThread) [root] SUCCESS:
<err> = ''; <rc> = 0 (commands:93)
21:32:59 2016-11-27 21:30:34,334 DEBUG (MainThread) [root]
/usr/bin/taskset --cpu-list 0-15 qemu-io -f qcow2 -c 'write -P 242
2048 1024' /var/tmp/tmpA0v1m6/vol2.img (cwd None) (commands:69)
21:32:59 2016-11-27 21:30:34,515 DEBUG (MainThread) [root] SUCCESS:
<err> = ''; <rc> = 0 (commands:93)
21:32:59 2016-11-27 21:30:34,515 DEBUG (MainThread) [root]
/usr/bin/taskset --cpu-list 0-15 /usr/bin/qemu-img create -f qcow2 -o
compat=1.1 -b /var/tmp/tmpA0v1m6/vol2.img /var/tmp/tmpA0v1m6/vol3.img
1048576 (cwd None) (commands:69)
21:32:59 2016-11-27 21:30:34,577 DEBUG (MainThread) [root] SUCCESS:
<err> = ''; <rc> = 0 (commands:93)
21:32:59 2016-11-27 21:30:34,577 DEBUG (MainThread) [root]
/usr/bin/taskset --cpu-list 0-15 qemu-io -f qcow2 -c 'write -P 243
3072 1024' /var/tmp/tmpA0v1m6/vol3.img (cwd None) (commands:69)
21:32:59 2016-11-27 21:30:34,750 DEBUG (MainThread) [root] SUCCESS:
<err> = ''; <rc> = 0 (commands:93)
21:32:59 2016-11-27 21:30:34,751 DEBUG (MainThread) [QemuImg]
/usr/bin/taskset --cpu-list 0-15 /usr/bin/nice -n 19 /usr/bin/ionice
-c 3 /usr/bin/qemu-img commit -p -t none -b
/var/tmp/tmpA0v1m6/vol0.img -f qcow2 /var/tmp/tmpA0v1m6/vol1.img (cwd
/var/tmp/tmpA0v1m6) (qemuimg:257)
21:32:59 2016-11-27 21:30:34,817 DEBUG (MainThread) [QemuImg] qemu-img
operation progress: 100.0% (qemuimg:323)
21:32:59 2016-11-27 21:30:34,818 DEBUG (MainThread) [root]
/usr/bin/taskset --cpu-list 0-15 qemu-io -f raw -c 'read -P 240 -s 0
-l 1024 0 1024' /var/tmp/tmpA0v1m6/vol0.img (cwd None) (commands:69)
21:32:59 2016-11-27 21:30:34,856 DEBUG (MainThread) [root] SUCCESS:
<err> = ''; <rc> = 0 (commands:93)
21:32:59 2016-11-27 21:30:34,857 DEBUG (MainThread) [root]
/usr/bin/taskset --cpu-list 0-15 qemu-io -f qcow2 -c 'read -P 241 -s 0
-l 1024 1024 1024' /var/tmp/tmpA0v1m6/vol0.img (cwd None)
(commands:69)
21:32:59 2016-11-27 21:30:34,890 DEBUG (MainThread) [root] SUCCESS:
<err> = "can't open device /var/tmp/tmpA0v1m6/vol0.img: Image is not
in qcow2 format\nno file open, try 'help open'\n"; <rc> = 0
(commands:93)
21:32:59 --------------------- >> end captured logging << ---------------------