Bug 960635

Summary: "Drive image file %s could not be found" message contains unparsed "%s"
Product: Red Hat Enterprise Virtualization Manager Reporter: Dafna Ron <dron>
Component: vdsmAssignee: Allon Mureinik <amureini>
Status: CLOSED UPSTREAM QA Contact: Aharon Canan <acanan>
Severity: low Docs Contact:
Priority: unspecified    
Version: 3.2.0CC: abaron, abonas, acathrow, amureini, bazulay, cboyle, gwatson, hateya, iheim, jkt, lpeer, Rhev-m-bugs, scohen, yeylon
Target Milestone: ---Keywords: Triaged
Target Release: 3.3.0Flags: amureini: needinfo-
abaron: Triaged+
Hardware: x86_64   
OS: Linux   
Whiteboard: storage
Fixed In Version: Doc Type: Bug Fix
Doc Text:
A malformed error was produced if a failure occurred while creating a volume: "Drive image file %s could not be found" This error could occur in any flow that creates a volume, and is not Live Storage Migration specific. The error text now reads: "Drive image file could not be found"
Story Points: ---
Clone Of:
: 982686 (view as bug list) Environment:
Last Closed: 2013-08-21 08:13:55 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Storage RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 982686    
Attachments:
Description Flags
logs none

Description Dafna Ron 2013-05-07 14:33:46 UTC
Created attachment 744771 [details]
logs

Description of problem:

I ran a vm on hsm host and restarted the vdsm on the hsm during the create volume step.
the live storage migration command fails and we report it 5 (not counting the INFO which also reports it)

(see more info)

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

sf15
vdsm-4.10.2-17.0.el6ev.x86_64

How reproducible:

100%

Steps to Reproduce:
1. create and run a vm on iscsi pool with 2 hosts
2. live migrate the vm's disk
3. restart the vdsm on the hsm when task createVolume appears in spm
 
Actual results:

we fail the move and engine reports it 5 times in the log which would make debugging deficult in case we have multiple vms

Expected results:

we should diminish the amount of reported errors in the log


Additional info: logs

2013-05-07 16:14:10,043 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-4-thread-46) [105ad651] Error code imageErr and error message VDSGenericException: VDSErrorException: Failed to VmReplicateDiskStartVDS, e
rror = Drive image file %s could not be found

2013-05-07 16:14:10,044 ERROR [org.ovirt.engine.core.vdsbroker.VDSCommandBase] (pool-4-thread-46) [105ad651] Command VmReplicateDiskStartVDS execution failed. Exception: VDSErrorException: VDSGenericException: VDSErrorException: Failed
to VmReplicateDiskStartVDS, error = Drive image file %s could not be found

2013-05-07 16:14:10,044 ERROR [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (pool-4-thread-46) [105ad651] Command org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand throw Vdc Bll exception. With error message VdcBLLException:
 Drive image file %s could not be found

2013-05-07 16:14:10,070 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-4-thread-46) [105ad651] Error code imageErr and error message VDSGenericException: VDSErrorException: Failed to VmReplicateDiskFinishVDS,
error = Drive image file %s could not be found

2013-05-07 16:14:10,070 ERROR [org.ovirt.engine.core.vdsbroker.VDSCommandBase] (pool-4-thread-46) [105ad651] Command VmReplicateDiskFinishVDS execution failed. Exception: VDSErrorException: VDSGenericException: VDSErrorException: Failed
 to VmReplicateDiskFinishVDS, error = Drive image file %s could not be found

Comment 1 Alissa 2013-07-09 12:04:05 UTC
First problem that needs a fix related to the specific error that the error doesn't contain the name of the image file, it's not properly replaced and will make troubleshooting more difficult: 
"Drive image file %s could not be found".

Second - regarding the multiple logging, it looks as this is not a storage related problem, but rather happens for many different commands.
Perhaps the bug should be splitted to handle the first issue in storage area, and the multiple logging to be handled on infra level - Ayal, your input on this?
The multiple logging is done in the following places:

BrokerCommandBase --> ProceedProxyReturnValue
VDSCommandBase --> setVdsRuntimeError

Comment 2 Ayal Baron 2013-07-09 13:52:12 UTC
(In reply to Alissa from comment #1)
> First problem that needs a fix related to the specific error that the error
> doesn't contain the name of the image file, it's not properly replaced and
> will make troubleshooting more difficult: 
> "Drive image file %s could not be found".

This means that we're lacking this information in the log?

> 
> Second - regarding the multiple logging, it looks as this is not a storage
> related problem, but rather happens for many different commands.
> Perhaps the bug should be splitted to handle the first issue in storage
> area, and the multiple logging to be handled on infra level - Ayal, your
> input on this?
> The multiple logging is done in the following places:
> 
> BrokerCommandBase --> ProceedProxyReturnValue
> VDSCommandBase --> setVdsRuntimeError

Sounds reasonable to me.
Please clone it, rename both to reflect the relevant problems etc.

Comment 3 Alissa 2013-07-09 14:43:06 UTC
(In reply to Ayal Baron from comment #2)
> (In reply to Alissa from comment #1)
> > First problem that needs a fix related to the specific error that the error
> > doesn't contain the name of the image file, it's not properly replaced and
> > will make troubleshooting more difficult: 
> > "Drive image file %s could not be found".
> 
> This means that we're lacking this information in the log?
yes. I think the incomplete message is originated like this in vdsm so the bug should be moved from engine to vdsm component - this is how it's declared in define.py (and it's not defined like this in engine code):
  'imageErr': {'status': {
        'code': 13,
        'message': 'Drive image file %s could not be found'}},

> > Second - regarding the multiple logging, it looks as this is not a storage
> > related problem, but rather happens for many different commands.
> > Perhaps the bug should be splitted to handle the first issue in storage
> > area, and the multiple logging to be handled on infra level - Ayal, your
> > input on this?
> > The multiple logging is done in the following places:
> > 
> > BrokerCommandBase --> ProceedProxyReturnValue
> > VDSCommandBase --> setVdsRuntimeError
> 
> Sounds reasonable to me.
> Please clone it, rename both to reflect the relevant problems etc.

Comment 8 Charlie 2013-11-28 00:33:32 UTC
This bug is currently attached to errata RHBA-2013:15291. If this change is not to be documented in the text for this errata please either remove it from the errata, set the requires_doc_text flag to 
minus (-), or leave a "Doc Text" value of "--no tech note required" if you do not have permission to alter the flag.

Otherwise to aid in the development of relevant and accurate release documentation, please fill out the "Doc Text" field above with these four (4) pieces of information:

* Cause: What actions or circumstances cause this bug to present.
* Consequence: What happens when the bug presents.
* Fix: What was done to fix the bug.
* Result: What now happens when the actions or circumstances above occur. (NB: this is not the same as 'the bug doesn't present anymore')

Once filled out, please set the "Doc Type" field to the appropriate value for the type of change made and submit your edits to the bug.

For further details on the Cause, Consequence, Fix, Result format please refer to:

https://bugzilla.redhat.com/page.cgi?id=fields.html#cf_release_notes 

Thanks in advance.

Comment 9 Charlie 2014-01-03 03:43:35 UTC
Hi could you tell me how this was fixed, for the errata text? Thanks

Comment 10 Allon Mureinik 2014-01-05 10:18:21 UTC
I updated the doctext field.
Thanks, Charlie.