On Tue, Nov 3, 2015 at 9:52 AM, Christophe TREFOIS < christophe.tref...@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. 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. > 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@ovirt.org > http://lists.ovirt.org/mailman/listinfo/users > >
_______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users