Bug 1408304 - Confusing errors when a volume does not exists in Volume.getInfo
Summary: Confusing errors when a volume does not exists in Volume.getInfo
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: vdsm
Classification: oVirt
Component: Core
Version: 4.18.0
Hardware: Unspecified
OS: Unspecified
unspecified
medium
Target Milestone: ovirt-4.1.5
: 4.19.27
Assignee: Ala Hino
QA Contact: Lilach Zitnitski
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-12-22 20:28 UTC by Nir Soffer
Modified: 2017-08-23 08:04 UTC (History)
4 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-08-23 08:04:40 UTC
oVirt Team: Storage
Embargoed:
rule-engine: ovirt-4.1+
rule-engine: exception+


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
oVirt gerrit 74463 0 master POST logging: Support not logging expected errors 2017-07-31 13:06:28 UTC
oVirt gerrit 79966 0 master MERGED logging: Handle exception logging when calling getVolumeInfo 2017-08-07 17:39:14 UTC
oVirt gerrit 79982 0 master MERGED logging: Fix logging expected errors in dispatcher 2017-08-07 17:39:10 UTC
oVirt gerrit 80013 0 master MERGED logging: Use str helper to better log the error message 2017-08-07 17:39:04 UTC
oVirt gerrit 80041 0 master ABANDONED logging: Support not logging expected errors 2017-08-08 12:43:09 UTC
oVirt gerrit 80042 0 master MERGED logging: Support not logging expected errors in storage tasks 2017-08-07 17:39:08 UTC
oVirt gerrit 80354 0 ovirt-4.1 MERGED logging: Use str helper to better log the error message 2017-08-08 12:01:48 UTC
oVirt gerrit 80355 0 ovirt-4.1 MERGED logging: Support not logging expected errors 2017-08-08 12:01:52 UTC
oVirt gerrit 80356 0 ovirt-4.1 MERGED logging: Support not logging expected errors in storage tasks 2017-08-08 12:01:56 UTC
oVirt gerrit 80357 0 ovirt-4.1 MERGED logging: Fix logging expected errors in dispatcher 2017-08-08 12:02:01 UTC
oVirt gerrit 80358 0 ovirt-4.1 MERGED logging: Handle exception logging when calling getVolumeInfo 2017-08-08 12:02:07 UTC

Description Nir Soffer 2016-12-22 20:28:35 UTC
Description of problem:

In some flows, we verify that the flow is successful by checking
if a volume exists using Volume.getInfo verb.

When the volume does not exists (expected), vdsm logs this
confusing traceback:

2016-12-22 22:04:06,010 ERROR (jsonrpc/3) [storage.TaskManager.Task] (Task='b34e2474-46d5-4590-81ce-d7644f8419dc') Unexpected error (task:870)
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/task.py", line 877, in _run
    return fn(*args, **kargs)
  File "/usr/lib/python2.7/site-packages/vdsm/logUtils.py", line 50, in wrapper
    res = f(*args, **kwargs)
  File "/usr/share/vdsm/storage/hsm.py", line 3050, in getVolumeInfo
    volUUID=volUUID).getInfo()
  File "/usr/share/vdsm/storage/sd.py", line 747, in produceVolume
    volUUID)
  File "/usr/share/vdsm/storage/fileVolume.py", line 361, in __init__
    manifest = self.manifestClass(repoPath, sdUUID, imgUUID, volUUID)
  File "/usr/share/vdsm/storage/fileVolume.py", line 61, in __init__
    volUUID)
  File "/usr/share/vdsm/storage/volume.py", line 84, in __init__
    self.validate()
  File "/usr/share/vdsm/storage/volume.py", line 107, in validate
    self.validateVolumePath()
  File "/usr/share/vdsm/storage/fileVolume.py", line 120, in validateVolumePath
    raise se.VolumeDoesNotExist(self.volUUID)
VolumeDoesNotExist: Volume does not exist: (u'877f7dd3-fba4-448c-b8e2-2ac44e368c22',)

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

How reproducible:
Always

Steps to Reproduce:
1. Call Volume.getInfo on non-existing volume

Actual results:
Confusing exception about expected condition.

Expected results:
Debug or info log about missing volume.

Additional info:

When a volume does not exists, getting volume information does
should return VolumeDoesNotExist error to engine, but there
is no need to log anything special in vdsm. Asking for info
about a volume is not an error in vdsm or in the client code.

However, if a volume does not exist in some other flow, this
is a fatal error that should fail loudly.

We cannot handle VolumeDoesNotExist error in a special way
and the lower level layer cannot throw another error when
a volume does not exits since the lower level layer has no
context.

One solution is to add an error wrapper that will expose
the original error code and message so it can be returned to
engine, but the top level error handler in vdsm can detect it
and avoid unhelpful logging.

A similar problem is client errors - calling with incorrect
or missing arguments. In v2v this is handled by ClientError
class.

This issue exist in other parts of the code, so we need
a generic solution that can be applied everywhere in 
a consistent way.

Comment 1 Allon Mureinik 2017-07-16 16:14:06 UTC
Ala, aren't you working on the same issue for a different BZ?

Comment 2 Ala Hino 2017-07-16 18:14:41 UTC
We have BZ 1442688 that is in the same area although it is opened against ovirt-engine.

Comment 3 Ala Hino 2017-08-07 18:18:05 UTC
Patches already merged to master, backported and verified on 4.1.
As the patches are quite straightforward and with low risk, they are safe to be backported to 4.1.5

Comment 4 Lilach Zitnitski 2017-08-14 09:16:10 UTC
--------------------------------------
Tested with the following code:
----------------------------------------
ovirt-engine-4.1.5.2-0.1.el7.noarch
vdsm-4.19.27-1.el7ev.x86_64

Tested with the following scenario:

Steps to Reproduce:
1. run volume.getInfo on non-existing volume

Actual results:
INFO message in vdsm.log getVolumeInfo error=Volume does not exist

Expected results:

Moving to VERIFIED!


Note You need to log in before you can comment on or make changes to this bug.