Vinzenz Feenstra has posted comments on this change.
Change subject: virt: Ensure not to handle no longer tacked fds in epoll
......................................................................
Patch Set 2:
(4 comments)
http://gerrit.ovirt.org/#/c/28179/2//COMMIT_MSG
Commit Message:
Line 5: CommitDate: 2014-05-28 14:53:28 +0200
Line 6:
Line 7: virt: Ensure not to handle no longer tacked fds in epoll
Line 8:
Line 9: In some cases it is possible that events from epoll are received before the
Please do - I'd love to understand the race that caused fd to
disappear fro
This is the backtrace:
Thread-623::INFO::2014-05-22 15:44:35,018::vm::4575::vm.Vm::(releaseVm)
vmId=`1c9f6b74-86b5-4173-aa8e-3e294ea9f3f2`::Release VM resources
Thread-623::DEBUG::2014-05-22 15:44:35,952::sampling::292::vm.Vm::(stop)
vmId=`1c9f6b74-86b5-4173-aa8e-3e294ea9f3f2`::Stop statistics collection
Thread-623::DEBUG::2014-05-22 15:44:35,998::vmChannels::205::vds::(unregister) Delete
fileno 136 from listener.
Thread-335::DEBUG::2014-05-22 15:44:36,007::sampling::323::vm.Vm::(run)
vmId=`1c9f6b74-86b5-4173-aa8e-3e294ea9f3f2`::Stats thread finished
VM Channels Listener::DEBUG::2014-05-22
15:44:36,129::vmChannels::112::vds::(_do_del_channels) fileno 136 was removed from
listener.
VM Channels Listener::ERROR::2014-05-22 15:44:36,584::vmChannels::176::vds::(run)
Unhandled exception caught in vm channels listener thread
Traceback (most recent call last):
File "/usr/share/vdsm/vmChannels.py", line 174, in run
File "/usr/share/vdsm/vmChannels.py", line 161, in _wait_for_events
File "/usr/share/vdsm/vmChannels.py", line 60, in _handle_event
KeyError: 136
VM Channels Listener::INFO::2014-05-22 15:44:36,603::vmChannels::178::vds::(run) VM
channels listener thread has ended.
Basically on that host where 50 vms while doing some scale testing. And this happend when
one of the vms was shutdown.
Thread1: guestIF::314::self._channelListener.unregister(self._sock.fileno())
Thread1: vmChannels::205::vds::(unregister) Delete fileno 136 from listener
Thread2: vmChannels::112::vds::(_do_del_channels) fileno 136 was removed from listener.
Thread2: epoll event received about incoming data from the virtio channel
Thread2: > vmChannels::176::vds::(run) Unhandled exception caught in vm channels
listener thread
Thread1: guestIF::322::self._sock.close() # This line is fake, but for demonstration
Line 10: socket is closed. This patch ensures that we're still tracking the fd for
Line 11: which we're receiving the event.
Line 12:
Line 13: Change-Id: Idde0f89d2859107dd1bb697d1753709137335677
Line 7: virt: Ensure not to handle no longer tacked fds in epoll
Line 8:
Line 9: In some cases it is possible that events from epoll are received before the
Line 10: socket is closed. This patch ensures that we're still tracking the fd for
Line 11: which we're receiving the event.
I think that a better wording of what this patch does is: this patch
ignore
true, I don't know where my head was again when I wrote this part.
Line 12:
Line 13: Change-Id: Idde0f89d2859107dd1bb697d1753709137335677
Line 14: Bug-Url:
https://bugzilla.redhat.com/1102072
http://gerrit.ovirt.org/#/c/28179/2/vdsm/virt/vmchannels.py
File vdsm/virt/vmchannels.py:
Line 58: self.log.debug("Received %.08X. On fd removed by
epoll.",
Line 59: event)
Line 60: elif (event & select.EPOLLIN):
Line 61: obj = self._channels.get(fileno, None)
Line 62: if obj:
if obj is not None:
even if fileno == 0 might be a valid or
not, the object is either None or a dict. Not sure why we would have to be that explicit
here.
Line 63: obj['reconnects'] = 0
Line 64: try:
Line 65: if obj['read_cb'](obj['opaque']):
Line 66: obj['read_time'] = time.time()
Line 69: except:
Line 70: self.log.exception("Exception on read callback.")
Line 71: else:
Line 72: self.log.debug("Received epoll event %.08X for no longer
"
Line 73: "tracked fd = %d", event, fileno)
Is this information of some use? I mean, we can possibly do something
knowi
I would mainly want to know if something like this happens, what are the event
flags passed. Since this seems to be very hard to reproduce, however it happend I would
like to keep some more info in there.
Line 74:
Line 75: if reconnect:
Line 76: self._prepare_reconnect(fileno)
Line 77:
--
To view, visit
http://gerrit.ovirt.org/28179
To unsubscribe, visit
http://gerrit.ovirt.org/settings
Gerrit-MessageType: comment
Gerrit-Change-Id: Idde0f89d2859107dd1bb697d1753709137335677
Gerrit-PatchSet: 2
Gerrit-Project: vdsm
Gerrit-Branch: master
Gerrit-Owner: Vinzenz Feenstra <vfeenstr(a)redhat.com>
Gerrit-Reviewer: Dan Kenigsberg <danken(a)redhat.com>
Gerrit-Reviewer: Francesco Romani <fromani(a)redhat.com>
Gerrit-Reviewer: Gal Hammer <ghammer(a)redhat.com>
Gerrit-Reviewer: Michal Skrivanek <michal.skrivanek(a)redhat.com>
Gerrit-Reviewer: Vinzenz Feenstra <vfeenstr(a)redhat.com>
Gerrit-Reviewer: automation(a)ovirt.org
Gerrit-Reviewer: oVirt Jenkins CI Server
Gerrit-HasComments: Yes