[JIRA] (OVIRT-2645) [VDSM] Tests mounting loop devices fail randomly again

[VDSM] Tests mounting loop devices fail randomly again ------------------------------------------------------ Key: OVIRT-2645 URL: https://ovirt-jira.atlassian.net/browse/OVIRT-2645 Project: oVirt - virtualization made easy Issue Type: By-EMAIL Reporter: Nir Soffer Assignee: infra We had this issue few years ago, and it was solved when we started to create loop devices to the slave in check-path.sh. Before we run the tests, we created loop devices. Looking at the log, we had 5 nodes and we added 3 nodes - this is typical log. + create_loop_devices 8 + local last=7 + local min ++ seq 0 7 + for min in '`seq 0 $last`' + local name=/dev/loop0 + '[' '!' -e /dev/loop0 ']' + for min in '`seq 0 $last`' + local name=/dev/loop1 + '[' '!' -e /dev/loop1 ']' + for min in '`seq 0 $last`' + local name=/dev/loop2 + '[' '!' -e /dev/loop2 ']' + for min in '`seq 0 $last`' + local name=/dev/loop3 + '[' '!' -e /dev/loop3 ']' + for min in '`seq 0 $last`' + local name=/dev/loop4 + '[' '!' -e /dev/loop4 ']' + for min in '`seq 0 $last`' + local name=/dev/loop5 + '[' '!' -e /dev/loop5 ']' + mknod --mode 0666 /dev/loop5 b 7 5 + for min in '`seq 0 $last`' + local name=/dev/loop6 + '[' '!' -e /dev/loop6 ']' + mknod --mode 0666 /dev/loop6 b 7 6 + for min in '`seq 0 $last`' + local name=/dev/loop7 + '[' '!' -e /dev/loop7 ']' + mknod --mode 0666 /dev/loop7 b 7 7 But mounting images failed later as you can see bellow. Failed build: https://jenkins.ovirt.org/blue/rest/organizations/jenkins/pipelines/vdsm_... The same tests run fine in travis inside a container: https://travis-ci.org/nirs/vdsm/jobs/471920126 Anyone has idea why mounting fail randomly in Jenkins slaves, and how we can fix this issue? ====================================================================== ERROR: Tests mkimage.mkFloppyFs creating an image and checking its content. ---------------------------------------------------------------------- Traceback (most recent call last): File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/tests/testlib.py", line 142, in wrapper return f(self, *args) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/tests/testValidation.py", line 194, in wrapper return f(*args, **kwargs) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/tests/mkimage_test.py", line 211, in test_mkFloppyFs floppy = mkimage.mkFloppyFs("vmId_floppy", self.files, label) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/mkimage.py", line 137, in mkFloppyFs injectFilesToFs(floppy, files, 'vfat') File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/mkimage.py", line 113, in injectFilesToFs m.mount(mntOpts='loop', vfstype=fstype) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/storage/mount.py", line 207, in mount cgroup=cgroup) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/storage/mount.py", line 277, in _mount _runcmd(cmd) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/storage/mount.py", line 305, in _runcmd raise MountError(rc, b";".join((out, err))) MountError: (32, ';mount: /tmp/vdsm-mkimage-testsxtGqen/images/vmId_floppy.e83b907eacb704d3942b8cab79561d2a.img: failed to setup loop device: No such file or directory\n') -------------------- >> begin captured logging << -------------------- 2019-01-08 23:46:19,720 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-1 /usr/sbin/mkfs.msdos -C /tmp/vdsm-mkimage-testsxtGqen/images/vmId_floppy.e83b907eacb704d3942b8cab79561d2a.img 1440 -n FSLABEL (cwd None) (commands:198) 2019-01-08 23:46:19,729 DEBUG (MainThread) [root] SUCCESS: <err> = ''; <rc> = 0 (commands:219) 2019-01-08 23:46:19,731 INFO (MainThread) [storage.Mount] mounting /tmp/vdsm-mkimage-testsxtGqen/images/vmId_floppy.e83b907eacb704d3942b8cab79561d2a.img at /tmp/tmpSejvmr (mount:204) 2019-01-08 23:46:19,731 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-1 /usr/bin/mount -t vfat -o loop /tmp/vdsm-mkimage-testsxtGqen/images/vmId_floppy.e83b907eacb704d3942b8cab79561d2a.img /tmp/tmpSejvmr (cwd None) (commands:198) 2019-01-08 23:46:19,743 DEBUG (MainThread) [root] FAILED: <err> = 'mount: /tmp/vdsm-mkimage-testsxtGqen/images/vmId_floppy.e83b907eacb704d3942b8cab79561d2a.img: failed to setup loop device: No such file or directory\n'; <rc> = 32 (commands:219) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: Tests mkimage.mkFloppyFs creating an image and checking its content. ---------------------------------------------------------------------- Traceback (most recent call last): File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/tests/testlib.py", line 142, in wrapper return f(self, *args) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/tests/testValidation.py", line 194, in wrapper return f(*args, **kwargs) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/tests/mkimage_test.py", line 211, in test_mkFloppyFs floppy = mkimage.mkFloppyFs("vmId_floppy", self.files, label) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/mkimage.py", line 137, in mkFloppyFs injectFilesToFs(floppy, files, 'vfat') File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/mkimage.py", line 113, in injectFilesToFs m.mount(mntOpts='loop', vfstype=fstype) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/storage/mount.py", line 207, in mount cgroup=cgroup) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/storage/mount.py", line 277, in _mount _runcmd(cmd) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/storage/mount.py", line 305, in _runcmd raise MountError(rc, b";".join((out, err))) MountError: (32, ';mount: /tmp/vdsm-mkimage-testsnlTJrM/images/vmId_floppy.4f26a597fe7f8a916fd808350e62bdc0.img: failed to setup loop device: No such file or directory\n') -------------------- >> begin captured logging << -------------------- 2019-01-08 23:46:19,750 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-1 /usr/sbin/mkfs.msdos -C /tmp/vdsm-mkimage-testsnlTJrM/images/vmId_floppy.4f26a597fe7f8a916fd808350e62bdc0.img 1440 (cwd None) (commands:198) 2019-01-08 23:46:19,759 DEBUG (MainThread) [root] SUCCESS: <err> = ''; <rc> = 0 (commands:219) 2019-01-08 23:46:19,761 INFO (MainThread) [storage.Mount] mounting /tmp/vdsm-mkimage-testsnlTJrM/images/vmId_floppy.4f26a597fe7f8a916fd808350e62bdc0.img at /tmp/tmpiDcstj (mount:204) 2019-01-08 23:46:19,762 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-1 /usr/bin/mount -t vfat -o loop /tmp/vdsm-mkimage-testsnlTJrM/images/vmId_floppy.4f26a597fe7f8a916fd808350e62bdc0.img /tmp/tmpiDcstj (cwd None) (commands:198) 2019-01-08 23:46:19,773 DEBUG (MainThread) [root] FAILED: <err> = 'mount: /tmp/vdsm-mkimage-testsnlTJrM/images/vmId_floppy.4f26a597fe7f8a916fd808350e62bdc0.img: failed to setup loop device: No such file or directory\n'; <rc> = 32 (commands:219) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: Test that mkimage.mkFloppyFs handle situation when the floppy image ---------------------------------------------------------------------- Traceback (most recent call last): File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/tests/testlib.py", line 142, in wrapper return f(self, *args) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/tests/testValidation.py", line 194, in wrapper return f(*args, **kwargs) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/tests/mkimage_test.py", line 230, in test_mkFloppyFs_overwrite floppy = mkimage.mkFloppyFs("vmId_floppy", self.files, label) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/mkimage.py", line 137, in mkFloppyFs injectFilesToFs(floppy, files, 'vfat') File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/mkimage.py", line 113, in injectFilesToFs m.mount(mntOpts='loop', vfstype=fstype) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/storage/mount.py", line 207, in mount cgroup=cgroup) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/storage/mount.py", line 277, in _mount _runcmd(cmd) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/storage/mount.py", line 305, in _runcmd raise MountError(rc, b";".join((out, err))) MountError: (32, ';mount: /tmp/vdsm-mkimage-testslSTYsV/images/vmId_floppy.3af4c566a929c30f605091dd7a5b7deb.img: failed to setup loop device: No such file or directory\n') -------------------- >> begin captured logging << -------------------- 2019-01-08 23:46:19,779 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-1 /usr/sbin/mkfs.msdos -C /tmp/vdsm-mkimage-testslSTYsV/images/vmId_floppy.3af4c566a929c30f605091dd7a5b7deb.img 1440 -n FSLABEL (cwd None) (commands:198) 2019-01-08 23:46:19,789 DEBUG (MainThread) [root] SUCCESS: <err> = ''; <rc> = 0 (commands:219) 2019-01-08 23:46:19,790 INFO (MainThread) [storage.Mount] mounting /tmp/vdsm-mkimage-testslSTYsV/images/vmId_floppy.3af4c566a929c30f605091dd7a5b7deb.img at /tmp/tmpX4UcrB (mount:204) 2019-01-08 23:46:19,791 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-1 /usr/bin/mount -t vfat -o loop /tmp/vdsm-mkimage-testslSTYsV/images/vmId_floppy.3af4c566a929c30f605091dd7a5b7deb.img /tmp/tmpX4UcrB (cwd None) (commands:198) 2019-01-08 23:46:19,803 DEBUG (MainThread) [root] FAILED: <err> = 'mount: /tmp/vdsm-mkimage-testslSTYsV/images/vmId_floppy.3af4c566a929c30f605091dd7a5b7deb.img: failed to setup loop device: No such file or directory\n'; <rc> = 32 (commands:219) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: Test that mkimage.mkFloppyFs handle situation when the floppy image ---------------------------------------------------------------------- Traceback (most recent call last): File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/tests/testlib.py", line 142, in wrapper return f(self, *args) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/tests/testValidation.py", line 194, in wrapper return f(*args, **kwargs) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/tests/mkimage_test.py", line 230, in test_mkFloppyFs_overwrite floppy = mkimage.mkFloppyFs("vmId_floppy", self.files, label) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/mkimage.py", line 137, in mkFloppyFs injectFilesToFs(floppy, files, 'vfat') File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/mkimage.py", line 113, in injectFilesToFs m.mount(mntOpts='loop', vfstype=fstype) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/storage/mount.py", line 207, in mount cgroup=cgroup) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/storage/mount.py", line 277, in _mount _runcmd(cmd) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/storage/mount.py", line 305, in _runcmd raise MountError(rc, b";".join((out, err))) MountError: (32, ';mount: /tmp/vdsm-mkimage-testsOy036Z/images/vmId_floppy.7d36c87a8c8c6c8ad83dc972edfcb3cc.img: failed to setup loop device: No such file or directory\n') -------------------- >> begin captured logging << -------------------- 2019-01-08 23:46:19,809 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-1 /usr/sbin/mkfs.msdos -C /tmp/vdsm-mkimage-testsOy036Z/images/vmId_floppy.7d36c87a8c8c6c8ad83dc972edfcb3cc.img 1440 (cwd None) (commands:198) 2019-01-08 23:46:19,821 DEBUG (MainThread) [root] SUCCESS: <err> = ''; <rc> = 0 (commands:219) 2019-01-08 23:46:19,822 INFO (MainThread) [storage.Mount] mounting /tmp/vdsm-mkimage-testsOy036Z/images/vmId_floppy.7d36c87a8c8c6c8ad83dc972edfcb3cc.img at /tmp/tmpJNTkWb (mount:204) 2019-01-08 23:46:19,823 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-1 /usr/bin/mount -t vfat -o loop /tmp/vdsm-mkimage-testsOy036Z/images/vmId_floppy.7d36c87a8c8c6c8ad83dc972edfcb3cc.img /tmp/tmpJNTkWb (cwd None) (commands:198) 2019-01-08 23:46:19,836 DEBUG (MainThread) [root] FAILED: <err> = 'mount: /tmp/vdsm-mkimage-testsOy036Z/images/vmId_floppy.7d36c87a8c8c6c8ad83dc972edfcb3cc.img: failed to setup loop device: No such file or directory\n'; <rc> = 32 (commands:219) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: Tests mkimage.mkIsoFs creating an image and checking its content ---------------------------------------------------------------------- Traceback (most recent call last): File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/tests/testlib.py", line 142, in wrapper return f(self, *args) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/tests/testValidation.py", line 194, in wrapper return f(*args, **kwargs) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/tests/mkimage_test.py", line 252, in test_mkIsoFs m.mount(mntOpts='loop') File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/storage/mount.py", line 207, in mount cgroup=cgroup) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/storage/mount.py", line 277, in _mount _runcmd(cmd) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/storage/mount.py", line 305, in _runcmd raise MountError(rc, b";".join((out, err))) MountError: (32, ';mount: /tmp/vdsm-mkimage-testsS16Km7/images/vmId_iso.1d6daeff12530405cbf56a511812e581.img: failed to setup loop device: No such file or directory\n') -------------------- >> begin captured logging << --------------------Coverage.py warning: Module /home/jenkins/workspace/vdsm_standard-check-patch/vdsm/vdsm was never imported. (module-not-imported) 2019-01-08 23:46:19,851 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-1 /usr/bin/mkisofs -R -J -o /tmp/vdsm-mkimage-testsS16Km7/images/vmId_iso.1d6daeff12530405cbf56a511812e581.img -V fslabel /tmp/tmphPPnKt (cwd None) (commands:198) 2019-01-08 23:46:19,882 DEBUG (MainThread) [root] SUCCESS: <err> = 'Total translation table size: 0\nTotal rockridge attributes bytes: 1796\nTotal directory bytes: 8192\nPath table size(bytes): 64\nMax brk space used 22000\n199 extents written (0 MB)\n'; <rc> = 0 (commands:219) 2019-01-08 23:46:19,885 INFO (MainThread) [storage.Mount] mounting /tmp/vdsm-mkimage-testsS16Km7/images/vmId_iso.1d6daeff12530405cbf56a511812e581.img at /tmp/vdsm-mkimage-testsS16Km7/work (mount:204) 2019-01-08 23:46:19,886 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-1 /usr/bin/mount -o loop /tmp/vdsm-mkimage-testsS16Km7/images/vmId_iso.1d6daeff12530405cbf56a511812e581.img /tmp/vdsm-mkimage-testsS16Km7/work (cwd None) (commands:198) 2019-01-08 23:46:19,898 DEBUG (MainThread) [root] FAILED: <err> = 'mount: /tmp/vdsm-mkimage-testsS16Km7/images/vmId_iso.1d6daeff12530405cbf56a511812e581.img: failed to setup loop device: No such file or directory\n'; <rc> = 32 (commands:219) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: Tests mkimage.mkIsoFs creating an image and checking its content ---------------------------------------------------------------------- Traceback (most recent call last): File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/tests/testlib.py", line 142, in wrapper return f(self, *args) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/tests/testValidation.py", line 194, in wrapper return f(*args, **kwargs) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/tests/mkimage_test.py", line 252, in test_mkIsoFs m.mount(mntOpts='loop') File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/storage/mount.py", line 207, in mount cgroup=cgroup) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/storage/mount.py", line 277, in _mount _runcmd(cmd) File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/storage/mount.py", line 305, in _runcmd raise MountError(rc, b";".join((out, err))) MountError: (32, ';mount: /tmp/vdsm-mkimage-testsxv7k7G/images/vmId_iso.afeec73d2b486c5f33df966a0306836a.img: failed to setup loop device: No such file or directory\n') -------------------- >> begin captured logging << -------------------- 2019-01-08 23:46:19,907 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-1 /usr/bin/mkisofs -R -J -o /tmp/vdsm-mkimage-testsxv7k7G/images/vmId_iso.afeec73d2b486c5f33df966a0306836a.img /tmp/tmpfk8az9 (cwd None) (commands:198) 2019-01-08 23:46:19,931 DEBUG (MainThread) [root] SUCCESS: <err> = 'Total translation table size: 0\nTotal rockridge attributes bytes: 1796\nTotal directory bytes: 8192\nPath table size(bytes): 64\nMax brk space used 22000\n199 extents written (0 MB)\n'; <rc> = 0 (commands:219) 2019-01-08 23:46:19,933 INFO (MainThread) [storage.Mount] mounting /tmp/vdsm-mkimage-testsxv7k7G/images/vmId_iso.afeec73d2b486c5f33df966a0306836a.img at /tmp/vdsm-mkimage-testsxv7k7G/work (mount:204) 2019-01-08 23:46:19,934 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-1 /usr/bin/mount -o loop /tmp/vdsm-mkimage-testsxv7k7G/images/vmId_iso.afeec73d2b486c5f33df966a0306836a.img /tmp/vdsm-mkimage-testsxv7k7G/work (cwd None) (commands:198) 2019-01-08 23:46:19,946 DEBUG (MainThread) [root] FAILED: <err> = 'mount: /tmp/vdsm-mkimage-testsxv7k7G/images/vmId_iso.afeec73d2b486c5f33df966a0306836a.img: failed to setup loop device: No such file or directory\n'; <rc> = 32 (commands:219) --------------------- >> end captured logging << ---------------------