Bug 1114499

Summary: refreshing iso list fails with: AttributeError: '_IOProcessFileUtils' object has no attribute 'validateQemuReadable'
Product: [Retired] oVirt Reporter: Yedidyah Bar David <didi>
Component: vdsmAssignee: Yeela Kaplan <ykaplan>
Status: CLOSED CURRENTRELEASE QA Contact: Jiri Belka <jbelka>
Severity: urgent Docs Contact:
Priority: unspecified    
Version: 3.5CC: amureini, bazulay, bugs, danken, dcaroest, ebenahar, gklein, iheim, istein, jbelka, mgoldboi, oourfali, rbalakri, sbonazzo, yeylon
Target Milestone: ---   
Target Release: 3.5.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard: infra
Fixed In Version: ovirt-3.5.0-beta1.1 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2014-10-17 12:33:05 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Infra RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---
Bug Depends On:    
Bug Blocks: 1073943    
Attachments:
Description Flags
vdsm.log none

Description Yedidyah Bar David 2014-06-30 09:09:06 UTC
Description of problem:

See summary

Version-Release number of selected component (if applicable):

Current master nightly snapshot

How reproducible:

Not sure

Steps to Reproduce:
1. install and setup engine with local iso domain
2. add a host
3. add an iso file to the iso domain
4. refresh

Actual results:

Fails, vdsm.log has:

Thread-61::ERROR::2014-06-30 11:27:57,441::task::866::Storage.TaskManager.Task::(_setError) Task=`d9c6310b-0b5f-4634-a380-13ea607584ea`::Unexpected error
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/task.py", line 873, in _run
    return fn(*args, **kargs)
  File "/usr/share/vdsm/logUtils.py", line 45, in wrapper
    res = f(*args, **kwargs)
  File "/usr/share/vdsm/storage/hsm.py", line 2324, in getIsoList
    caseSensitive=False)
  File "/usr/share/vdsm/storage/fileSD.py", line 285, in getFileList
    self.oop.fileUtils.validateQemuReadable(entry)
AttributeError: '_IOProcessFileUtils' object has no attribute 'validateQemuReadable'

Expected results:

Succeeds

Additional info:

Comment 1 Yedidyah Bar David 2014-06-30 09:24:45 UTC
Workaround, following Dan's suggestion:

Edit /etc/vdsm/vdsm.conf to have:

[irs]
oop_impl = rfh

and restart vdsm.

Comment 2 Yeela Kaplan 2014-07-07 10:55:29 UTC
*** Bug 1116561 has been marked as a duplicate of this bug. ***

Comment 3 Sandro Bonazzola 2014-07-11 08:16:38 UTC
*** Bug 1114057 has been marked as a duplicate of this bug. ***

Comment 4 Sandro Bonazzola 2014-07-11 09:31:49 UTC
*** Bug 1114052 has been marked as a duplicate of this bug. ***

Comment 5 Yeela Kaplan 2014-07-13 07:45:28 UTC
*** Bug 1117688 has been marked as a duplicate of this bug. ***

Comment 6 Jiri Belka 2014-08-07 12:49:08 UTC
Created attachment 924900 [details]
vdsm.log

Images on ISO domain still not visible, please check newly added vdsm.log. If different issue please let me know, I'll file new BZ and make this one depend on it.

~~~
...snip...
Thread-127::ERROR::2014-08-07 14:48:03,222::task::866::Storage.TaskManager.Task::(_setError) Task=`adb45a68-d297-46d0-89fe-c1da4e9cdb45`::Unexpected error
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/task.py", line 873, in _run
    return fn(*args, **kargs)
  File "/usr/share/vdsm/logUtils.py", line 45, in wrapper
    res = f(*args, **kwargs)
  File "/usr/share/vdsm/storage/hsm.py", line 2302, in getFileStats
    caseSensitive=caseSensitive)
  File "/usr/share/vdsm/storage/fileSD.py", line 281, in getFileList
    st = self.oop.os.stat(entry)
  File "/usr/share/vdsm/storage/outOfProcess.py", line 241, in stat
    return self._iop.stat(path)
  File "/usr/lib/python2.6/site-packages/ioprocess/__init__.py", line 367, in stat
    resdict = self._sendCommand("stat", {"path": path}, self.timeout)
  File "/usr/lib/python2.6/site-packages/ioprocess/__init__.py", line 344, in _sendCommand
    raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
...snip...
Thread-127::ERROR::2014-08-07 14:48:03,225::dispatcher::79::Storage.Dispatcher::(wrapper) [Errno 2] No such file or directory
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/dispatcher.py", line 71, in wrapper
    result = ctask.prepare(func, *args, **kwargs)
  File "/usr/share/vdsm/storage/task.py", line 103, in wrapper
    return m(self, *a, **kw)
  File "/usr/share/vdsm/storage/task.py", line 1179, in prepare
    raise self.error
OSError: [Errno 2] No such file or directory
~~~

Comment 7 Jiri Belka 2014-08-07 12:49:30 UTC
# rpm -qa vdsm\*
vdsm-jsonrpc-4.16.1-6.gita4a4614.el6.noarch
vdsm-4.16.1-6.gita4a4614.el6.x86_64
vdsm-python-zombiereaper-4.16.1-6.gita4a4614.el6.noarch
vdsm-xmlrpc-4.16.1-6.gita4a4614.el6.noarch
vdsm-yajsonrpc-4.16.1-6.gita4a4614.el6.noarch
vdsm-cli-4.16.1-6.gita4a4614.el6.noarch
vdsm-python-4.16.1-6.gita4a4614.el6.x86_64

Comment 8 Dan Kenigsberg 2014-08-13 14:37:58 UTC
Yes, Jiri. It is a different issue. You found a race in getFileList: it globs for the filenames, then calls stat() and validateQemuReadable(), assuming the files would stay there forever.

Could it be that you (or someone else) were removing files from the ISO domain while verifying this bug? Is this traceback reproducible? In any case, please open a new BZ.

Comment 9 Dan Kenigsberg 2014-08-13 14:51:13 UTC
Or could it be that the ISO domain was actually empty?

Thread-127::DEBUG::2014-08-07 14:17:28,088::task::885::Storage.TaskManager.Task::(_run) Task=`95de7f78-5405-420b-b231-c62ff9be9c21`::Task._run: 95de7f78-5405-420b-b231-c62ff9be9c21 ('0c78b4d6-ba00-4d3e-9f9f-65c7d5899d71', '*.iso', False) {} failed - stopping task

Comment 10 Yeela Kaplan 2014-08-13 14:51:52 UTC
Jiri,
It does not fail on the original problem(validateQemuReadable but on stat). It's a different issue,
and we might need a separate bug for this.

What ioprocess version did you use to verify this?
It might be that you need a newer version

Comment 11 Jiri Belka 2014-08-14 08:10:09 UTC
Workaround in #1 doesn't work for me anymore.

New BZ1130024 for issue in #6.

Question from #8, #9 - no iso domain was ok, not empty and nobody was touching it iirc.

Comment 12 Yeela Kaplan 2014-08-14 08:24:25 UTC
Moving back to ON_QA.

Workaround was to switch to use rfh for outOfProcess, instead of ioprocess.
It's a different issue that is unrelated to ioprocess and needs to be investigated.

This bug needs to be verified in a different, clean environment because it is unrelated to the new bug,
or depend on the new bug.

Comment 13 Yeela Kaplan 2014-08-14 09:46:44 UTC
Jiri,
could you verify it on a clean environment because of the urgency?
thanks

Comment 14 Jiri Belka 2014-08-14 12:38:30 UTC
ok, no traceback related to issue as described in #8 and #10, tested on clean rhel6 host.

although there's still stat() issue as described in #10.

vdsm-python-zombiereaper-4.16.1-6.gita4a4614.el6.noarch
vdsm-jsonrpc-4.16.1-6.gita4a4614.el6.noarch
python-ioprocess-0.5.0-1.el6.noarch
vdsm-xmlrpc-4.16.1-6.gita4a4614.el6.noarch
vdsm-yajsonrpc-4.16.1-6.gita4a4614.el6.noarch
vdsm-4.16.1-6.gita4a4614.el6.x86_64
vdsm-python-4.16.1-6.gita4a4614.el6.x86_64
vdsm-cli-4.16.1-6.gita4a4614.el6.noarch

Comment 15 Sandro Bonazzola 2014-10-17 12:33:05 UTC
oVirt 3.5 has been released and should include the fix for this issue.