Bug 1416315

Summary: [z-stream clone - 4.0.6-1] schema inconsistencies flooding logs
Product: Red Hat Enterprise Virtualization Manager Reporter: rhev-integ
Component: vdsmAssignee: Irit Goihman <igoihman>
Status: CLOSED ERRATA QA Contact: Petr Matyáš <pmatyas>
Severity: medium Docs Contact:
Priority: high    
Version: 4.0.6CC: amarchuk, bazulay, danken, gklein, gveitmic, igoihman, lsurette, lsvaty, mgoldboi, mkalinin, mperina, oourfali, srevivo, ycui, ykaul
Target Milestone: ovirt-4.0.6-1Keywords: WorkAround, ZStream
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: 1416278 Environment:
Last Closed: 2017-02-09 13:33:38 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Infra RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On: 1416278    
Bug Blocks: 1418398    

Description rhev-integ 2017-01-25 09:17:49 UTC 
+++ This bug is a downstream clone. The original bug is: +++
+++   bug 1416278 +++
======================================================================

Description of problem:

vdsm flooding logs. Apparently this started after 4.0.6 upgrade.

On getAllVmStats, each VM generates a _report_inconsistency.

It goes like in the format below:

jsonrpc.Executor/0::DEBUG::2017-01-23 09:01:05,876::__init__::530::jsonrpc.JsonRpcServer::(_handle_request) Calling 'Host.getAllVmStats' in bridge with {}
jsonrpc.Executor/0::WARNING::2017-01-23 09:01:05,902::vdsmapi::147::devel::(_report_inconsistency) Provided parameters {...} do not match any of union VmStats values 
jsonrpc.Executor/0::WARNING::2017-01-23 09:01:05,904::vdsmapi::147::devel::(_report_inconsistency) Provided parameters {...} do not match any of union VmStats values 
jsonrpc.Executor/0::WARNING::2017-01-23 09:01:05,905::vdsmapi::147::devel::(_report_inconsistency) Provided parameters {...} do not match any of union VmStats values 
jsonrpc.Executor/0::WARNING::2017-01-23 09:01:05,908::vdsmapi::147::devel::(_report_inconsistency) Provided parameters {...} do not match any of union VmStats values 
[....]

Each {...} above is for each VM (see attached log file for more details).

How reproducible:
100%

In our labs, everything seems to fail schema check, not just getAllVmStats (our vdsm is slightly newer 4.0.6). Host devices, storage...

jsonrpc.Executor/2::WARNING::2017-01-25 01:26:59,383::vdsmapi::147::devel::(_report_inconsistency) Parameter spmLver is not int type
jsonrpc.Executor/5::WARNING::2017-01-25 01:27:00,422::vdsmapi::147::devel::(_report_inconsistency) Following parameters ['type'] were not recognized
jsonrpc.Executor/5::WARNING::2017-01-25 01:27:00,422::vdsmapi::147::devel::(_report_inconsistency) Parameter lver is not int type
jsonrpc.Executor/5::WARNING::2017-01-25 01:27:00,422::vdsmapi::147::devel::(_report_inconsistency) Parameter version is not int type
jsonrpc.Executor/5::WARNING::2017-01-25 01:27:00,422::vdsmapi::147::devel::(_report_inconsistency) Required property domainType is not provided when calling StoragePool.getInfo
jsonrpc.Executor/5::WARNING::2017-01-25 01:27:00,423::vdsmapi::147::devel::(_report_inconsistency) Following parameters ['isoprefix'] were not recognized
jsonrpc.Executor/5::WARNING::2017-01-25 01:27:00,423::vdsmapi::147::devel::(_report_inconsistency) Parameter diskfree is not int type
jsonrpc.Executor/5::WARNING::2017-01-25 01:27:00,423::vdsmapi::147::devel::(_report_inconsistency) Parameter disktotal is not int type
jsonrpc.Executor/5::WARNING::2017-01-25 01:27:00,423::vdsmapi::147::devel::(_report_inconsistency) Following parameters ['isoprefix'] were not recognized
jsonrpc.Executor/5::WARNING::2017-01-25 01:27:00,423::vdsmapi::147::devel::(_report_inconsistency) Required property diskfree is not provided when calling StoragePool.getInfo
jsonrpc.Executor/5::WARNING::2017-01-25 01:27:00,423::vdsmapi::147::devel::(_report_inconsistency) Required property disktotal is not provided when calling StoragePool.getInfo
jsonrpc.Executor/5::WARNING::2017-01-25 01:27:00,423::vdsmapi::147::devel::(_report_inconsistency) Required property version is not provided when calling StoragePool.getInfo


jsonrpc.Executor/2::WARNING::2017-01-25 01:25:54,719::vdsmapi::147::devel::(_report_inconsistency) Parameter {'pci_0000_ff_17_0': {'params': {'product': 'Xeon E7 v3/Xeon E5 v3/Core i7 Integra
ted Memory Controller 1 Channel 0 Thermal Control', 'vendor': 'Intel Corporation', 'product_id': '0x2fd0', 'parent': 'computer', 'vendor_id': '0x8086', 'driver': 'hswep_uncore', 'capability':
 'pci', 'is_assignable': 'true', 'address': {'slot': '23', 'bus': '255', 'domain': '0', 'function': '0'}}}, 'pci_0000_ff_17_4': {'params': {'product': 'Xeon E7 v3/Xeon E5 v3/Core i7 DDRIO (VM
SE) 2 & 3', 'vendor': 'Intel Corporation', 'product_id': '0x2fb8', 'parent': 'computer', 'vendor_id': '0x8086', 'capability': 'pci', 'is_assignable': 'true', 'address': {'slot': '23', 'bus': 
'255', 'domain': '0', 'function': '4'}}}, 'pci_0000_ff_17_5': {'params': {'product': 'Xeon E7 v3/Xeon E5 v3/Core i7 DDRIO (VMSE) 2 [...]

Version-Release number of selected component (if applicable):
ovirt-engine-4.0.6.3-0.1.el7ev.noarch
vdsm-4.18.15.3-1.el7ev (4.0.5)

We have internally a similar issue on (our labs)
ovirt-engine-4.0.6.3-0.1.el7ev.noarch
vdsm-4.18.21-1.el7ev.x86_64

This doesn't seem to make much difference on our labs, it's still flooding the same way.
https://gerrit.ovirt.org/#/c/59512/
https://bugzilla.redhat.com/show_bug.cgi?id=1348256
[devel]
python_warnings_enable = false

Actual results:
vdsm.log and /var/log/messages flooded, hosts running low on space.

Expected results:
No flooding of logs due to schema inconsistencies.

(Originally by Germano Veit Michel)
Comment 15 Jiri Belka 2017-02-01 16:55:01 UTC 
ok, vdsm-api-4.18.21.1-1.el7ev.noarch

# sed -n '143,+5p' /usr/lib/python2.7/site-packages/api/vdsmapi.py
    def _report_inconsistency(self, message):
        if self._strict_mode:
            raise JsonRpcInvalidParamsError(message)

    def verify_args(self, class_name, method_name, args):
        try:

# grep ,devel /etc/vdsm/logger.conf 
keys=root,vds,Storage,virt,ovirt_hosted_engine_ha,ovirt_hosted_engine_ha_config,IOProcess,connectivity,devel

# sed -n '/logger_devel/,+1p' /etc/vdsm/logger.conf 
[logger_devel]
level=ERROR
# grep -i vdsmapi /var/log/vdsm/vdsm.log
Comment 19 errata-xmlrpc 2017-02-09 13:33:38 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHBA-2017-0265.html