[ovirt-users] Unknown libvirterror - where to start?

Fri Nov 6 13:32:35 UTC 2015

> On 06 Nov 2015, at 13:35, Martin Sivak <msivak at redhat.com> wrote:
> 
> Hi,
> 
>> Thread-8108::DEBUG::2015-11-03 08:47:31,410::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2
>> message: metadata not found: Requested metadata element is not present
> 
> we fixed this on vdsm side of oVirt 3.6 too:
> 
> https://gerrit.ovirt.org/#/c/45799/
> 
> But Nir is correct. This was just noise, it went away when any QoS was
> defined for the VM and was not important otherwise.
> 
>>> VM Channels Listener::DEBUG::2015-11-03 08:47:34,386::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 125.
>> We've seen this as well. I don't think there's a specific bug filed on this issue. I wonder if they related.

nope
unless there is a ridiculous number of them
they are about ovirt agent connectivity (which breaks around time of start/stop/migration, etc) but normally should not happen, when you run ovirt-guest-agent inside guest
When you don’t you’ll see it every so often per each VM


> 
> No relation to the metadata log messages. Can't help here.
> 
> Best regards
> 
> --
> Martin Sivak
> SLA / oVirt
> 
> 
> On Fri, Nov 6, 2015 at 1:14 PM, Christophe TREFOIS
> <christophe.trefois at uni.lu> wrote:
>> Dear Nir,
>> 
>> Thank you for your help. I shall ignore the messages then :)
>> 
>> Kind regards,
>> 
>> —
>> Christophe
>> 
>> Dr Christophe Trefois, Dipl.-Ing.
>> Technical Specialist / Post-Doc
>> 
>> UNIVERSITÉ DU LUXEMBOURG
>> 
>> LUXEMBOURG CENTRE FOR SYSTEMS BIOMEDICINE
>> Campus Belval | House of Biomedicine
>> 6, avenue du Swing
>> L-4367 Belvaux
>> T: +352 46 66 44 6124
>> F: +352 46 66 44 6949
>> http://www.uni.lu/lcsb
>> 
>> 
>> 
>> ----
>> This message is confidential and may contain privileged information.
>> It is intended for the named recipient only.
>> If you receive it in error please notify me and permanently delete the original message and any copies.
>> ----
>> 
>> 
>> 
>>> On 06 Nov 2015, at 12:23, Nir Soffer <nsoffer at redhat.com> wrote:
>>> 
>>> On Tue, Nov 3, 2015 at 10:30 AM, Yaniv Kaul <ykaul at redhat.com> wrote:
>>>> On Tue, Nov 3, 2015 at 9:52 AM, Christophe TREFOIS
>>>> <christophe.trefois at uni.lu> wrote:
>>>>> 
>>>>> Hi,
>>>>> 
>>>>> I checked the logs on my hypervisor that contains also the overt-engine
>>>>> (self-hosted) and I see strange unknown libvirterrors that come periodically
>>>>> in the vdsm.log file. The storage is glusterFS running on the hypervisor as
>>>>> well, one NFS export domain and an ISO domain. A NFS domain from another
>>>>> place is in maintenance mode.
>>>>> 
>>>>> I am running oVirt 3.5.3.
>>>>> 
>>>>> Thank you for any pointers as to where to start fixing this issue.
>>>>> 
>>>>> — log excerpt --
>>>>> 
>>>>> Thread-1947641::DEBUG::2015-11-03
>>>>> 08:47:31,398::stompReactor::163::yajsonrpc.StompServer::(send) Sending
>>>>> response
>>>>> Thread-8108::DEBUG::2015-11-03
>>>>> 08:47:31,410::libvirtconnection::143::root::(wrapper) Unknown libvirterror:
>>>>> ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata
>>>>> element is not present
>>>> 
>>>> 
>>>> This (depending on your host OS version, 6.x or 7.x) is either
>>>> https://bugzilla.redhat.com/show_bug.cgi?id=1220474 or
>>>> https://bugzilla.redhat.com/show_bug.cgi?id=1260864
>>>> Y.
>>> 
>>> The error about missing metadata is just noise in the log, nothing to
>>> worry about.
>>> 
>>> Adding Martin
>>> 
>>>> 
>>>>> Dummy-1895260::DEBUG::2015-11-03
>>>>> 08:47:31,477::storage_mailbox::731::Storage.Misc.excCmd::(_checkForMail) dd
>>>>> if=/rhev/data-center/00000002-0002-0002-0002-0000000003d5/mastersd/dom_md/inbox
>>>>> iflag=direct,fullblock count=1 bs=1024000 (cwd None)
>>>>> Dummy-1895260::DEBUG::2015-11-03
>>>>> 08:47:31,501::storage_mailbox::731::Storage.Misc.excCmd::(_checkForMail)
>>>>> SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB)
>>>>> copied, 0.00331278 s, 309 MB/s\n'; <rc> = 0
>>>>> Thread-7913::DEBUG::2015-11-03
>>>>> 08:47:32,298::libvirtconnection::143::root::(wrapper) Unknown libvirterror:
>>>>> ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata
>>>>> element is not present
>>>>> Thread-5682::DEBUG::2015-11-03
>>>>> 08:47:32,417::libvirtconnection::143::root::(wrapper) Unknown libvirterror:
>>>>> ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata
>>>>> element is not present
>>>>> Detector thread::DEBUG::2015-11-03
>>>>> 08:47:32,591::protocoldetector::187::vds.MultiProtocolAcceptor::(_add_connection)
>>>>> Adding connection from 127.0.0.1:44671
>>>>> Detector thread::DEBUG::2015-11-03
>>>>> 08:47:32,598::protocoldetector::201::vds.MultiProtocolAcceptor::(_remove_connection)
>>>>> Connection removed from 127.0.0.1:44671
>>>>> Detector thread::DEBUG::2015-11-03
>>>>> 08:47:32,599::protocoldetector::247::vds.MultiProtocolAcceptor::(_handle_connection_read)
>>>>> Detected protocol xml from 127.0.0.1:44671
>>>>> Detector thread::DEBUG::2015-11-03
>>>>> 08:47:32,599::BindingXMLRPC::1173::XmlDetector::(handleSocket) xml over http
>>>>> detected from ('127.0.0.1', 44671)
>>>>> Thread-1947642::DEBUG::2015-11-03
>>>>> 08:47:32,602::task::595::Storage.TaskManager.Task::(_updateState)
>>>>> Task=`1d99a166-cb9a-4025-8211-a48e210b5234`::moving from state init -> state
>>>>> preparing
>>>>> Thread-1947642::INFO::2015-11-03
>>>>> 08:47:32,603::logUtils::44::dispatcher::(wrapper) Run and protect:
>>>>> repoStats(options=None)
>>>>> Thread-1947642::INFO::2015-11-03
>>>>> 08:47:32,603::logUtils::47::dispatcher::(wrapper) Run and protect:
>>>>> repoStats, Return response: {u'de9eb737-691f-4622-9070-891531d599a0':
>>>>> {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay':
>>>>> '0.000373613', 'lastCheck': '2.5', 'valid': True},
>>>>> u'fe4fd19a-8714-44e0-ae41-663a4b62da7a': {'code': 0, 'actual': True,
>>>>> 'version': 0, 'acquired': True, 'delay': '0.000409446', 'lastCheck': '6.4',
>>>>> 'valid': True}, u'8253a89b-651e-4ff4-865b-57adef05d383': {'code': 0,
>>>>> 'actual': True, 'version': 3, 'acquired': True, 'delay': '0.000520671',
>>>>> 'lastCheck': '1.8', 'valid': True}, 'b18eb29e-8bb1-45b9-a60e-a8e07210e066':
>>>>> {'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay':
>>>>> '0.000424445', 'lastCheck': '6.5', 'valid': True}}
>>>>> Thread-1947642::DEBUG::2015-11-03
>>>>> 08:47:32,603::task::1191::Storage.TaskManager.Task::(prepare)
>>>>> Task=`1d99a166-cb9a-4025-8211-a48e210b5234`::finished:
>>>>> {u'de9eb737-691f-4622-9070-891531d599a0': {'code': 0, 'actual': True,
>>>>> 'version': 0, 'acquired': True, 'delay': '0.000373613', 'lastCheck': '2.5',
>>>>> 'valid': True}, u'fe4fd19a-8714-44e0-ae41-663a4b62da7a': {'code': 0,
>>>>> 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000409446',
>>>>> 'lastCheck': '6.4', 'valid': True}, u'8253a89b-651e-4ff4-865b-57adef05d383':
>>>>> {'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay':
>>>>> '0.000520671', 'lastCheck': '1.8', 'valid': True},
>>>>> 'b18eb29e-8bb1-45b9-a60e-a8e07210e066': {'code': 0, 'actual': True,
>>>>> 'version': 3, 'acquired': True, 'delay': '0.000424445', 'lastCheck': '6.5',
>>>>> 'valid': True}}
>>>>> Thread-1947642::DEBUG::2015-11-03
>>>>> 08:47:32,603::task::595::Storage.TaskManager.Task::(_updateState)
>>>>> Task=`1d99a166-cb9a-4025-8211-a48e210b5234`::moving from state preparing ->
>>>>> state finished
>>>>> Thread-1947642::DEBUG::2015-11-03
>>>>> 08:47:32,604::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll)
>>>>> Owner.releaseAll requests {} resources {}
>>>>> Thread-1947642::DEBUG::2015-11-03
>>>>> 08:47:32,604::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll)
>>>>> Owner.cancelAll requests {}
>>>>> Thread-1947642::DEBUG::2015-11-03
>>>>> 08:47:32,604::task::993::Storage.TaskManager.Task::(_decref)
>>>>> Task=`1d99a166-cb9a-4025-8211-a48e210b5234`::ref 0 aborting False
>>>>> Thread-6348::DEBUG::2015-11-03
>>>>> 08:47:33,261::libvirtconnection::143::root::(wrapper) Unknown libvirterror:
>>>>> ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata
>>>>> element is not present
>>>>> Thread-7286::DEBUG::2015-11-03
>>>>> 08:47:33,462::libvirtconnection::143::root::(wrapper) Unknown libvirterror:
>>>>> ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata
>>>>> element is not present
>>>>> Dummy-1895260::DEBUG::2015-11-03
>>>>> 08:47:33,514::storage_mailbox::731::Storage.Misc.excCmd::(_checkForMail) dd
>>>>> if=/rhev/data-center/00000002-0002-0002-0002-0000000003d5/mastersd/dom_md/inbox
>>>>> iflag=direct,fullblock count=1 bs=1024000 (cwd None)
>>>>> Dummy-1895260::DEBUG::2015-11-03
>>>>> 08:47:33,540::storage_mailbox::731::Storage.Misc.excCmd::(_checkForMail)
>>>>> SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB)
>>>>> copied, 0.00385901 s, 265 MB/s\n'; <rc> = 0
>>>>> Thread-7627::DEBUG::2015-11-03
>>>>> 08:47:33,938::libvirtconnection::143::root::(wrapper) Unknown libvirterror:
>>>>> ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata
>>>>> element is not present
>>>>> Thread-7951::DEBUG::2015-11-03
>>>>> 08:47:33,938::libvirtconnection::143::root::(wrapper) Unknown libvirterror:
>>>>> ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata
>>>>> element is not present
>>>>> Thread-3882::DEBUG::2015-11-03
>>>>> 08:47:33,940::libvirtconnection::143::root::(wrapper) Unknown libvirterror:
>>>>> ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata
>>>>> element is not present
>>>>> Thread-7967::DEBUG::2015-11-03
>>>>> 08:47:33,940::libvirtconnection::143::root::(wrapper) Unknown libvirterror:
>>>>> ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata
>>>>> element is not present
>>>>> Thread-7899::DEBUG::2015-11-03
>>>>> 08:47:33,951::libvirtconnection::143::root::(wrapper) Unknown libvirterror:
>>>>> ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata
>>>>> element is not present
>>>>> VM Channels Listener::DEBUG::2015-11-03
>>>>> 08:47:34,383::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 133.
>>>>> VM Channels Listener::DEBUG::2015-11-03
>>>>> 08:47:34,383::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 135.
>>>>> VM Channels Listener::DEBUG::2015-11-03
>>>>> 08:47:34,383::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 136.
>>>>> VM Channels Listener::DEBUG::2015-11-03
>>>>> 08:47:34,383::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 146.
>>>>> VM Channels Listener::DEBUG::2015-11-03
>>>>> 08:47:34,384::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 160.
>>>>> VM Channels Listener::DEBUG::2015-11-03
>>>>> 08:47:34,384::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 161.
>>>>> VM Channels Listener::DEBUG::2015-11-03
>>>>> 08:47:34,384::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 167.
>>>>> VM Channels Listener::DEBUG::2015-11-03
>>>>> 08:47:34,384::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 171.
>>>>> VM Channels Listener::DEBUG::2015-11-03
>>>>> 08:47:34,384::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 172.
>>>>> VM Channels Listener::DEBUG::2015-11-03
>>>>> 08:47:34,384::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 159.
>>>>> VM Channels Listener::DEBUG::2015-11-03
>>>>> 08:47:34,385::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 189.
>>>>> VM Channels Listener::DEBUG::2015-11-03
>>>>> 08:47:34,385::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 190.
>>>>> VM Channels Listener::DEBUG::2015-11-03
>>>>> 08:47:34,385::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 195.
>>>>> VM Channels Listener::DEBUG::2015-11-03
>>>>> 08:47:34,385::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 197.
>>>>> VM Channels Listener::DEBUG::2015-11-03
>>>>> 08:47:34,385::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 198.
>>>>> VM Channels Listener::DEBUG::2015-11-03
>>>>> 08:47:34,385::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 213.
>>>>> VM Channels Listener::DEBUG::2015-11-03
>>>>> 08:47:34,386::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 215.
>>>>> VM Channels Listener::DEBUG::2015-11-03
>>>>> 08:47:34,386::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 98.
>>>>> VM Channels Listener::DEBUG::2015-11-03
>>>>> 08:47:34,386::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 125.
>>>> 
>>>> 
>>>> We've seen this as well. I don't think there's a specific bug filed on this
>>>> issue. I wonder if they related.
>>>> Y.
>>> 
>>> Adding Vinzenz
>>> 
>>>> 
>>>>> 
>>>>> JsonRpc (StompReactor)::DEBUG::2015-11-03
>>>>> 08:47:34,412::stompReactor::98::Broker.StompAdapter::(handle_frame) Handling
>>>>> message <StompFrame command='SEND'>
>>>>> JsonRpcServer::DEBUG::2015-11-03
>>>>> 08:47:34,413::__init__::530::jsonrpc.JsonRpcServer::(serve_requests) Waiting
>>>>> for request
>>>>> Thread-1947643::DEBUG::2015-11-03
>>>>> 08:47:34,437::stompReactor::163::yajsonrpc.StompServer::(send) Sending
>>>>> response
>>>>> Thread-7613::DEBUG::2015-11-03
>>>>> 08:47:34,713::libvirtconnection::143::root::(wrapper) Unknown libvirterror:
>>>>> ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata
>>>>> element is not present
>>>>> Thread-6393::DEBUG::2015-11-03
>>>>> 08:47:34,713::libvirtconnection::143::root::(wrapper) Unknown libvirterror:
>>>>> ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata
>>>>> element is not present
>>>>> Thread-226941::DEBUG::2015-11-03
>>>>> 08:47:35,511::task::595::Storage.TaskManager.Task::(_updateState)
>>>>> Task=`bdf26401-324c-4220-9034-19c7d816f642`::moving from state init -> state
>>>>> preparing
>>>>> Thread-4709::DEBUG::2015-11-03
>>>>> 08:47:35,511::task::595::Storage.TaskManager.Task::(_updateState)
>>>>> Task=`0ac2f854-41e3-4427-a0f4-5eaa1842e212`::moving from state init -> state
>>>>> preparing
>>>>> 
>>>>> --
>>>>> 
>>>>> Christophe
>>>>> 
>>>>> 
>>>>> 
>>>>> _______________________________________________
>>>>> Users mailing list
>>>>> Users at ovirt.org
>>>>> http://lists.ovirt.org/mailman/listinfo/users
>>>>> 
>>>> 
>>>> 
>>>> _______________________________________________
>>>> Users mailing list
>>>> Users at ovirt.org
>>>> http://lists.ovirt.org/mailman/listinfo/users
>> 
> _______________________________________________
> Users mailing list
> Users at ovirt.org
> http://lists.ovirt.org/mailman/listinfo/users
> 
>