Re: [ovirt-devel] [ OST Failure Report ] [ oVirt master ] [ 25.1.17 ] [hotplug_disk]

[Nir Soffer]

On Thu, Jan 26, 2017 at 9:46 AM, Yaniv Kaul  wrote:
> I'm seeing a failure in 4.1, which I've never seen in the past:
> 2017-01-26 02:21:00,124 ERROR (mailbox-spm) [storage.MailBox.SpmMailMonitor]
> SPM_MailMonitor: mailbox 2 checksum failed, not clearing mailbox, clearing
> newMail. (storage_mailbox:618)

I have seen this in the past, this is a very rare error.

I'm not clear why this happens, if it has any effect or how we can avoid it.

Best open a bug about it, we should investigate it.

> (from host1).
>
> There are also some new warnings around monitoring, such as:
> 2017-01-26 02:20:58,035 WARN  (libvirt/events) [virt.vm]
> (vmId='85e8df3c-8bdf-470f-8c28-baa521d663de') unknown eventid 8 args
> ('/rhev/data-center/27d461cd-03b2-4b2b-a1f8-157c27bb710e/2e10aa41-24f1-4c83-8e29-15f772a2d04b/images/304c3f03-61a6-4b79-a748-174a4cd24f84/3f96ca05-e8f3-41f2-8b9c-c7d170b24f92',
> 3, 0, 8) (clientIF:540)

This means that libvirt sent an event that we are not handling, there is nothing
to warn about.

Since this event is a change in system state, having an info level log
would be nice.

The number 8 is not very helpful, we need to map the number to the event name
as documented in libvirt.
https://libvirt.org/html/libvirt-libvirt-domain.html#virDomainEventID

Ala is working on handling this and other events during live merge for 4.2.

> On Wed, Jan 25, 2017 at 2:17 PM, Gil Shinar  wrote:
>>
>> Link to job:
>> http://jenkins.ovirt.org/job/test-repo_ovirt_experimental_master/4951/
>>
>> Sorry for the mistake
>>
>> On Wed, Jan 25, 2017 at 1:43 PM, Gil Shinar  wrote:
>>>
>>> Hi,
>>>
>>> The test in $subject has failed. Below please find exception I have found
>>> in engine.log.
>>>
>>> {"jsonrpc": "2.0", "id": "4b8eb810-c52d-4c92-a792-e554f87c9493", "error":
>>> {"message": "Cannot deactivate Logical Volume: ('General Storage Exception:
>>> (\"5 [] [\\'  WARNING: Not using lvmetad because config setting
>>> use_lvmetad=0.\\', \\'  WARNING: To avoid corruption, rescan devices to make
>>> changes visible (pvscan --cache).\\', \\'  Logical volume
>>> f9dce023-0282-4185-9ad9-fe71c3975106/778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5 in
>>> use.\\', \\'  Logical volume
>>> f9dce023-0282-4185-9ad9-fe71c3975106/ab4e8962-6196-485e-be2a-d5791a38eaeb in
>>> use.\\']nf9dce023-0282-4185-9ad9-fe71c3975106/[\\'778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5\\',
>>> \\'ab4e8962-6196-485e-be2a-d5791a38eaeb\\']\",)',)", "code": 552}}�
>>>
>>> 2017-01-25 05:05:49,037-05 DEBUG
>>> [org.ovirt.vdsm.jsonrpc.client.internal.ResponseWorker] (ResponseWorker) []
>>> Message received: {"jsonrpc": "2.0", "id":
>>> "4b8eb810-c52d-4c92-a792-e554f87c9493", "error": {"message": "Cannot
>>> deactivate Logical Volume: ('General Storage Exception: (\"5 [] [\\'
>>> WARNING: Not using lvmetad because config setting use_lvmetad=0.\\', \\'
>>> WARNING: To avoid corruption, rescan devices to make changes visible (pvscan
>>> --cache).\\', \\'  Logical volume
>>> f9dce023-0282-4185-9ad9-fe71c3975106/778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5 in
>>> use.\\', \\'  Logical volume
>>> f9dce023-0282-4185-9ad9-fe71c3975106/ab4e8962-6196-485e-be2a-d5791a38eaeb in
>>> use.\\']nf9dce023-0282-4185-9ad9-fe71c3975106/[\\'778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5\\',
>>> \\'ab4e8962-6196-485e-be2a-d5791a38eaeb\\']\",)',)", "code": 552}}
>>> 2017-01-25 05:05:49,047-05 ERROR
>>> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
>>> (DefaultQuartzScheduler5) [59ab00f1] EVENT_ID:
>>> VDS_BROKER_COMMAND_FAILURE(10,802), Correlation ID: null, Call Stack: null,
>>> Custom Event ID: -1, Message: VDSM lago-basic-suite-master-host0 command
>>> TeardownImageVDS failed: Cannot deactivate Logical Volume: ('General Storage
>>> Exception: ("5 [] [\'  WARNING: Not using lvmetad because config setting
>>> use_lvmetad=0.\', \'  WARNING: To avoid corruption, rescan devices to make
>>> changes visible (pvscan --cache).\', \'  Logical volume
>>> f9dce023-0282-4185-9ad9-fe71c3975106/778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5 in
>>> use.\', \'  Logical volume
>>> f9dce023-0282-4185-9ad9-fe71c3975106/ab4e8962-6196-485e-be2a-d5791a38eaeb in
>>> use.\']\\nf9dce023-0282-4185-9ad9-fe71c3975106/[\'778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5\',
>>> \'ab4e8962-6196-485e-be2a-d5791a38eaeb\']",)',)
>>> 2017-01-25 05:05:49,047-05 ERROR
>>> [org.ovirt.engine.core.vdsbroker.vdsbroker.TeardownImageVDSCommand]
>>> (DefaultQuartzScheduler5) [59ab00f1] Command
>>> 'TeardownImageVDSCommand(HostName = lago-basic-suite-master-host0,
>>> ImageActionsVDSCommandParameters:{runAsync='true',
>>> hostId='60e52527-b637-445c-b408-0275d347e76a'})' execution failed:
>>> VDSGenericException: VDSErrorException: Failed in vdscommand to
>>> TeardownImageVDS, error = Cannot deactivate Logical Volume: ('General
>>> Storage Exception: ("5 [] [\'  WARNING: Not using lvmetad because config
>>> setting use_lvmetad=0.\', \'  WARNING: To avoid corruption, rescan devices
>>> to make changes 

Re: [ovirt-devel] [ OST Failure Report ] [ oVirt master ] [ 25.1.17 ] [hotplug_disk]

[Gil Shinar]

Link to job:
http://jenkins.ovirt.org/job/test-repo_ovirt_experimental_master/4951/

Sorry for the mistake

On Wed, Jan 25, 2017 at 1:43 PM, Gil Shinar  wrote:

> Hi,
>
> The test in $subject has failed. Below please find exception I have found
> in engine.log.
>
> {"jsonrpc": "2.0", "id": "4b8eb810-c52d-4c92-a792-e554f87c9493", "error": 
> {"message": "Cannot deactivate Logical Volume: ('General Storage Exception: 
> (\"5 [] [\\'  WARNING: Not using lvmetad because config setting 
> use_lvmetad=0.\\', \\'  WARNING: To avoid corruption, rescan devices to make 
> changes visible (pvscan --cache).\\', \\'  Logical volume 
> f9dce023-0282-4185-9ad9-fe71c3975106/778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5 in 
> use.\\', \\'  Logical volume 
> f9dce023-0282-4185-9ad9-fe71c3975106/ab4e8962-6196-485e-be2a-d5791a38eaeb in 
> use.\\']nf9dce023-0282-4185-9ad9-fe71c3975106/[\\'778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5\\',
>  \\'ab4e8962-6196-485e-be2a-d5791a38eaeb\\']\",)',)", "code": 552}}�
>
> 2017-01-25 05:05:49,037-05 DEBUG 
> [org.ovirt.vdsm.jsonrpc.client.internal.ResponseWorker] (ResponseWorker) [] 
> Message received: {"jsonrpc": "2.0", "id": 
> "4b8eb810-c52d-4c92-a792-e554f87c9493", "error": {"message": "Cannot 
> deactivate Logical Volume: ('General Storage Exception: (\"5 [] [\\'  
> WARNING: Not using lvmetad because config setting use_lvmetad=0.\\', \\'  
> WARNING: To avoid corruption, rescan devices to make changes visible (pvscan 
> --cache).\\', \\'  Logical volume 
> f9dce023-0282-4185-9ad9-fe71c3975106/778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5 in 
> use.\\', \\'  Logical volume 
> f9dce023-0282-4185-9ad9-fe71c3975106/ab4e8962-6196-485e-be2a-d5791a38eaeb in 
> use.\\']nf9dce023-0282-4185-9ad9-fe71c3975106/[\\'778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5\\',
>  \\'ab4e8962-6196-485e-be2a-d5791a38eaeb\\']\",)',)", "code": 552}}
> 2017-01-25 05:05:49,047-05 ERROR 
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] 
> (DefaultQuartzScheduler5) [59ab00f1] EVENT_ID: 
> VDS_BROKER_COMMAND_FAILURE(10,802), Correlation ID: null, Call Stack: null, 
> Custom Event ID: -1, Message: VDSM lago-basic-suite-master-host0 command 
> TeardownImageVDS failed: Cannot deactivate Logical Volume: ('General Storage 
> Exception: ("5 [] [\'  WARNING: Not using lvmetad because config setting 
> use_lvmetad=0.\', \'  WARNING: To avoid corruption, rescan devices to make 
> changes visible (pvscan --cache).\', \'  Logical volume 
> f9dce023-0282-4185-9ad9-fe71c3975106/778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5 in 
> use.\', \'  Logical volume 
> f9dce023-0282-4185-9ad9-fe71c3975106/ab4e8962-6196-485e-be2a-d5791a38eaeb in 
> use.\']\\nf9dce023-0282-4185-9ad9-fe71c3975106/[\'778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5\',
>  \'ab4e8962-6196-485e-be2a-d5791a38eaeb\']",)',)
> 2017-01-25 05:05:49,047-05 ERROR 
> [org.ovirt.engine.core.vdsbroker.vdsbroker.TeardownImageVDSCommand] 
> (DefaultQuartzScheduler5) [59ab00f1] Command 
> 'TeardownImageVDSCommand(HostName = lago-basic-suite-master-host0, 
> ImageActionsVDSCommandParameters:{runAsync='true', 
> hostId='60e52527-b637-445c-b408-0275d347e76a'})' execution failed: 
> VDSGenericException: VDSErrorException: Failed in vdscommand to 
> TeardownImageVDS, error = Cannot deactivate Logical Volume: ('General Storage 
> Exception: ("5 [] [\'  WARNING: Not using lvmetad because config setting 
> use_lvmetad=0.\', \'  WARNING: To avoid corruption, rescan devices to make 
> changes visible (pvscan --cache).\', \'  Logical volume 
> f9dce023-0282-4185-9ad9-fe71c3975106/778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5 in 
> use.\', \'  Logical volume 
> f9dce023-0282-4185-9ad9-fe71c3975106/ab4e8962-6196-485e-be2a-d5791a38eaeb in 
> use.\']\\nf9dce023-0282-4185-9ad9-fe71c3975106/[\'778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5\',
>  \'ab4e8962-6196-485e-be2a-d5791a38eaeb\']",)',)
> 2017-01-25 05:05:49,047-05 DEBUG 
> [org.ovirt.engine.core.vdsbroker.vdsbroker.TeardownImageVDSCommand] 
> (DefaultQuartzScheduler5) [59ab00f1] Exception: 
> org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: 
> VDSGenericException: VDSErrorException: Failed in vdscommand to 
> TeardownImageVDS, error = Cannot deactivate Logical Volume: ('General Storage 
> Exception: ("5 [] [\'  WARNING: Not using lvmetad because config setting 
> use_lvmetad=0.\', \'  WARNING: To avoid corruption, rescan devices to make 
> changes visible (pvscan --cache).\', \'  Logical volume 
> f9dce023-0282-4185-9ad9-fe71c3975106/778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5 in 
> use.\', \'  Logical volume 
> f9dce023-0282-4185-9ad9-fe71c3975106/ab4e8962-6196-485e-be2a-d5791a38eaeb in 
> use.\']\\nf9dce023-0282-4185-9ad9-fe71c3975106/[\'778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5\',
>  \'ab4e8962-6196-485e-be2a-d5791a38eaeb\']",)',)
>   at 
> org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.proceedProxyReturnValue(BrokerCommandBase.java:182)
>  [vdsbroker.jar:]
>   at 
> 

[ovirt-devel] [ OST Failure Report ] [ oVirt master ] [ 25.1.17 ] [hotplug_disk]

[Gil Shinar]

Hi,

The test in $subject has failed. Below please find exception I have found
in engine.log.

{"jsonrpc": "2.0", "id": "4b8eb810-c52d-4c92-a792-e554f87c9493",
"error": {"message": "Cannot deactivate Logical Volume: ('General
Storage Exception: (\"5 [] [\\'  WARNING: Not using lvmetad because
config setting use_lvmetad=0.\\', \\'  WARNING: To avoid corruption,
rescan devices to make changes visible (pvscan --cache).\\', \\'
Logical volume 
f9dce023-0282-4185-9ad9-fe71c3975106/778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5
in use.\\', \\'  Logical volume
f9dce023-0282-4185-9ad9-fe71c3975106/ab4e8962-6196-485e-be2a-d5791a38eaeb
in 
use.\\']nf9dce023-0282-4185-9ad9-fe71c3975106/[\\'778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5\\',
\\'ab4e8962-6196-485e-be2a-d5791a38eaeb\\']\",)',)", "code": 552}}�

2017-01-25 05:05:49,037-05 DEBUG
[org.ovirt.vdsm.jsonrpc.client.internal.ResponseWorker]
(ResponseWorker) [] Message received: {"jsonrpc": "2.0", "id":
"4b8eb810-c52d-4c92-a792-e554f87c9493", "error": {"message": "Cannot
deactivate Logical Volume: ('General Storage Exception: (\"5 [] [\\'
WARNING: Not using lvmetad because config setting use_lvmetad=0.\\',
\\'  WARNING: To avoid corruption, rescan devices to make changes
visible (pvscan --cache).\\', \\'  Logical volume
f9dce023-0282-4185-9ad9-fe71c3975106/778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5
in use.\\', \\'  Logical volume
f9dce023-0282-4185-9ad9-fe71c3975106/ab4e8962-6196-485e-be2a-d5791a38eaeb
in 
use.\\']nf9dce023-0282-4185-9ad9-fe71c3975106/[\\'778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5\\',
\\'ab4e8962-6196-485e-be2a-d5791a38eaeb\\']\",)',)", "code": 552}}
2017-01-25 05:05:49,047-05 ERROR
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(DefaultQuartzScheduler5) [59ab00f1] EVENT_ID:
VDS_BROKER_COMMAND_FAILURE(10,802), Correlation ID: null, Call Stack:
null, Custom Event ID: -1, Message: VDSM lago-basic-suite-master-host0
command TeardownImageVDS failed: Cannot deactivate Logical Volume:
('General Storage Exception: ("5 [] [\'  WARNING: Not using lvmetad
because config setting use_lvmetad=0.\', \'  WARNING: To avoid
corruption, rescan devices to make changes visible (pvscan
--cache).\', \'  Logical volume
f9dce023-0282-4185-9ad9-fe71c3975106/778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5
in use.\', \'  Logical volume
f9dce023-0282-4185-9ad9-fe71c3975106/ab4e8962-6196-485e-be2a-d5791a38eaeb
in 
use.\']\\nf9dce023-0282-4185-9ad9-fe71c3975106/[\'778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5\',
\'ab4e8962-6196-485e-be2a-d5791a38eaeb\']",)',)
2017-01-25 05:05:49,047-05 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.TeardownImageVDSCommand]
(DefaultQuartzScheduler5) [59ab00f1] Command
'TeardownImageVDSCommand(HostName = lago-basic-suite-master-host0,
ImageActionsVDSCommandParameters:{runAsync='true',
hostId='60e52527-b637-445c-b408-0275d347e76a'})' execution failed:
VDSGenericException: VDSErrorException: Failed in vdscommand to
TeardownImageVDS, error = Cannot deactivate Logical Volume: ('General
Storage Exception: ("5 [] [\'  WARNING: Not using lvmetad because
config setting use_lvmetad=0.\', \'  WARNING: To avoid corruption,
rescan devices to make changes visible (pvscan --cache).\', \'
Logical volume 
f9dce023-0282-4185-9ad9-fe71c3975106/778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5
in use.\', \'  Logical volume
f9dce023-0282-4185-9ad9-fe71c3975106/ab4e8962-6196-485e-be2a-d5791a38eaeb
in 
use.\']\\nf9dce023-0282-4185-9ad9-fe71c3975106/[\'778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5\',
\'ab4e8962-6196-485e-be2a-d5791a38eaeb\']",)',)
2017-01-25 05:05:49,047-05 DEBUG
[org.ovirt.engine.core.vdsbroker.vdsbroker.TeardownImageVDSCommand]
(DefaultQuartzScheduler5) [59ab00f1] Exception:
org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException:
VDSGenericException: VDSErrorException: Failed in vdscommand to
TeardownImageVDS, error = Cannot deactivate Logical Volume: ('General
Storage Exception: ("5 [] [\'  WARNING: Not using lvmetad because
config setting use_lvmetad=0.\', \'  WARNING: To avoid corruption,
rescan devices to make changes visible (pvscan --cache).\', \'
Logical volume 
f9dce023-0282-4185-9ad9-fe71c3975106/778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5
in use.\', \'  Logical volume
f9dce023-0282-4185-9ad9-fe71c3975106/ab4e8962-6196-485e-be2a-d5791a38eaeb
in 
use.\']\\nf9dce023-0282-4185-9ad9-fe71c3975106/[\'778cbc5b-a9df-46d7-bc80-1a66f7d3e2b5\',
\'ab4e8962-6196-485e-be2a-d5791a38eaeb\']",)',)
at 
org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.proceedProxyReturnValue(BrokerCommandBase.java:182)
[vdsbroker.jar:]
at 
org.ovirt.engine.core.vdsbroker.vdsbroker.ImageActionsVDSCommandBase.executeVdsBrokerCommand(ImageActionsVDSCommandBase.java:20)
[vdsbroker.jar:]
at 
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:111)
[vdsbroker.jar:]
at 
org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:73)
[vdsbroker.jar:]
at