[ovirt-users] Unknown libvirterror - where to start?
Christophe TREFOIS
christophe.trefois at uni.lu
Sun Dec 6 12:20:26 EST 2015
HI michal,
Thanks for the tips. We're now deploying the agents on all VMs (around 60) and will see for similar entries in the logs.
Have a nice evening,
--
Christophe
> -----Original Message-----
> From: Michal Skrivanek [mailto:mskrivan at redhat.com]
> Sent: vendredi 6 novembre 2015 14:33
> To: Christophe TREFOIS <christophe.trefois at uni.lu>
> Cc: users at ovirt.org
> Subject: Re: [ovirt-users] Unknown libvirterror - where to start?
>
>
> > 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::(_checkFo
> >>>>> rMail) 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::(_checkFo
> >>>>> rMail)
> >>>>> 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::(_checkFo
> >>>>> rMail) 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::(_checkFo
> >>>>> rMail)
> >>>>> 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_request
> >>>>> s) 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
> >
> >
More information about the Users
mailing list