[VDSM] Test failure test_reject_concurrency(True) (protocoldetectorTests.AcceptorTests)

test_reject_concurrency(True) (protocoldetectorTests.AcceptorTests) fails once every few month. Looks like a real issue in the actual code, doing double close. This is a known issue in asyncore that we already fixed in few places. Nir ---- 11:26:48 ====================================================================== 11:26:48 ERROR: test_reject_concurrency(True) (protocoldetectorTests.AcceptorTests) 11:26:48 ---------------------------------------------------------------------- 11:26:48 Traceback (most recent call last): 11:26:48 File "/home/jenkins/workspace/vdsm_master_check-patch-fc24-x86_64/vdsm/tests/protocoldetectorTests.py", line 113, in tearDown 11:26:48 self.acceptor.stop() 11:26:48 File "/home/jenkins/workspace/vdsm_master_check-patch-fc24-x86_64/vdsm/lib/vdsm/protocoldetector.py", line 211, in stop 11:26:48 self._acceptor.close() 11:26:48 File "/usr/lib64/python2.7/asyncore.py", line 407, in close 11:26:48 self.del_channel() 11:26:48 File "/home/jenkins/workspace/vdsm_master_check-patch-fc24-x86_64/vdsm/lib/yajsonrpc/betterAsyncore.py", line 137, in del_channel 11:26:48 asyncore.dispatcher.del_channel(self, map) 11:26:48 File "/usr/lib64/python2.7/asyncore.py", line 292, in del_channel 11:26:48 del map[fd] 11:26:48 KeyError: 63 11:26:48 -------------------- >> begin captured logging << -------------------- 11:26:48 2016-09-11 11:24:27,399 INFO [vds.MultiProtocolAcceptor] (MainThread) Listening at 127.0.0.1:46615 11:26:48 2016-09-11 11:24:27,399 DEBUG [vds.MultiProtocolAcceptor] (MainThread) Adding detector <protocoldetectorTests.Echo object at 0x7f03ee0b01d0> 11:26:48 2016-09-11 11:24:27,399 DEBUG [vds.MultiProtocolAcceptor] (MainThread) Adding detector <protocoldetectorTests.Uppercase object at 0x7f03ee0b0c50> 11:26:48 2016-09-11 11:24:27,402 INFO [ProtocolDetector.AcceptorImpl] (Thread-191) Accepting connection from 127.0.0.1:38136 11:26:48 2016-09-11 11:24:27,407 INFO [ProtocolDetector.AcceptorImpl] (Thread-191) Accepting connection from 127.0.0.1:38138 11:26:48 2016-09-11 11:24:27,411 INFO [ProtocolDetector.AcceptorImpl] (Thread-191) Accepting connection from 127.0.0.1:38140 11:26:48 2016-09-11 11:24:27,415 INFO [ProtocolDetector.AcceptorImpl] (Thread-191) Accepting connection from 127.0.0.1:38142 11:26:48 2016-09-11 11:24:27,416 DEBUG [ProtocolDetector.Detector] (Thread-191) Using required_size=9 11:26:48 2016-09-11 11:24:27,416 WARNING [vds.dispatcher] (Thread-191) unhandled write event 11:26:48 2016-09-11 11:24:27,420 INFO [ProtocolDetector.AcceptorImpl] (Thread-191) Accepting connection from 127.0.0.1:38144 11:26:48 2016-09-11 11:24:27,421 WARNING [ProtocolDetector.Detector] (Thread-191) Unrecognized protocol: 'no such p' 11:26:48 2016-09-11 11:24:27,427 DEBUG [ProtocolDetector.Detector] (Thread-191) Using required_size=9 11:26:48 2016-09-11 11:24:27,427 WARNING [vds.dispatcher] (Thread-191) unhandled write event 11:26:48 2016-09-11 11:24:27,428 DEBUG [ProtocolDetector.Detector] (Thread-191) Using required_size=9 11:26:48 2016-09-11 11:24:27,428 WARNING [vds.dispatcher] (Thread-191) unhandled write event 11:26:48 2016-09-11 11:24:27,429 WARNING [ProtocolDetector.Detector] (Thread-191) Unrecognized protocol: 'no such p' 11:26:48 2016-09-11 11:24:27,430 WARNING [ProtocolDetector.Detector] (Thread-191) Unrecognized protocol: 'no such p' 11:26:48 2016-09-11 11:24:27,430 DEBUG [ProtocolDetector.Detector] (Thread-191) Using required_size=9 11:26:48 2016-09-11 11:24:27,431 WARNING [ProtocolDetector.Detector] (Thread-191) Unrecognized protocol: 'no such p' 11:26:48 2016-09-11 11:24:27,433 DEBUG [ProtocolDetector.Detector] (Thread-191) Using required_size=9 11:26:48 2016-09-11 11:24:27,433 WARNING [ProtocolDetector.Detector] (Thread-191) Unrecognized protocol: 'no such p' 11:26:48 2016-09-11 11:24:27,434 DEBUG [vds.MultiProtocolAcceptor] (MainThread) Stopping Acceptor 11:26:48 --------------------- >> end captured logging << ---------------------

Will take a look. On Mon, Sep 12, 2016 at 12:13 PM, Nir Soffer <nsoffer@redhat.com> wrote:
test_reject_concurrency(True) (protocoldetectorTests.AcceptorTests) fails once every few month.
Looks like a real issue in the actual code, doing double close. This is a known issue in asyncore that we already fixed in few places.
Nir
----
11:26:48 ====================================================================== 11:26:48 ERROR: test_reject_concurrency(True) (protocoldetectorTests.AcceptorTests) 11:26:48 ---------------------------------------------------------------------- 11:26:48 Traceback (most recent call last): 11:26:48 File "/home/jenkins/workspace/vdsm_master_check-patch-fc24-x86_64/vdsm/tests/protocoldetectorTests.py", line 113, in tearDown 11:26:48 self.acceptor.stop() 11:26:48 File "/home/jenkins/workspace/vdsm_master_check-patch-fc24-x86_64/vdsm/lib/vdsm/protocoldetector.py", line 211, in stop 11:26:48 self._acceptor.close() 11:26:48 File "/usr/lib64/python2.7/asyncore.py", line 407, in close 11:26:48 self.del_channel() 11:26:48 File "/home/jenkins/workspace/vdsm_master_check-patch-fc24-x86_64/vdsm/lib/yajsonrpc/betterAsyncore.py", line 137, in del_channel 11:26:48 asyncore.dispatcher.del_channel(self, map) 11:26:48 File "/usr/lib64/python2.7/asyncore.py", line 292, in del_channel 11:26:48 del map[fd] 11:26:48 KeyError: 63 11:26:48 -------------------- >> begin captured logging << -------------------- 11:26:48 2016-09-11 11:24:27,399 INFO [vds.MultiProtocolAcceptor] (MainThread) Listening at 127.0.0.1:46615 11:26:48 2016-09-11 11:24:27,399 DEBUG [vds.MultiProtocolAcceptor] (MainThread) Adding detector <protocoldetectorTests.Echo object at 0x7f03ee0b01d0> 11:26:48 2016-09-11 11:24:27,399 DEBUG [vds.MultiProtocolAcceptor] (MainThread) Adding detector <protocoldetectorTests.Uppercase object at 0x7f03ee0b0c50> 11:26:48 2016-09-11 11:24:27,402 INFO [ProtocolDetector.AcceptorImpl] (Thread-191) Accepting connection from 127.0.0.1:38136 11:26:48 2016-09-11 11:24:27,407 INFO [ProtocolDetector.AcceptorImpl] (Thread-191) Accepting connection from 127.0.0.1:38138 11:26:48 2016-09-11 11:24:27,411 INFO [ProtocolDetector.AcceptorImpl] (Thread-191) Accepting connection from 127.0.0.1:38140 11:26:48 2016-09-11 11:24:27,415 INFO [ProtocolDetector.AcceptorImpl] (Thread-191) Accepting connection from 127.0.0.1:38142 11:26:48 2016-09-11 11:24:27,416 DEBUG [ProtocolDetector.Detector] (Thread-191) Using required_size=9 11:26:48 2016-09-11 11:24:27,416 WARNING [vds.dispatcher] (Thread-191) unhandled write event 11:26:48 2016-09-11 11:24:27,420 INFO [ProtocolDetector.AcceptorImpl] (Thread-191) Accepting connection from 127.0.0.1:38144 11:26:48 2016-09-11 11:24:27,421 WARNING [ProtocolDetector.Detector] (Thread-191) Unrecognized protocol: 'no such p' 11:26:48 2016-09-11 11:24:27,427 DEBUG [ProtocolDetector.Detector] (Thread-191) Using required_size=9 11:26:48 2016-09-11 11:24:27,427 WARNING [vds.dispatcher] (Thread-191) unhandled write event 11:26:48 2016-09-11 11:24:27,428 DEBUG [ProtocolDetector.Detector] (Thread-191) Using required_size=9 11:26:48 2016-09-11 11:24:27,428 WARNING [vds.dispatcher] (Thread-191) unhandled write event 11:26:48 2016-09-11 11:24:27,429 WARNING [ProtocolDetector.Detector] (Thread-191) Unrecognized protocol: 'no such p' 11:26:48 2016-09-11 11:24:27,430 WARNING [ProtocolDetector.Detector] (Thread-191) Unrecognized protocol: 'no such p' 11:26:48 2016-09-11 11:24:27,430 DEBUG [ProtocolDetector.Detector] (Thread-191) Using required_size=9 11:26:48 2016-09-11 11:24:27,431 WARNING [ProtocolDetector.Detector] (Thread-191) Unrecognized protocol: 'no such p' 11:26:48 2016-09-11 11:24:27,433 DEBUG [ProtocolDetector.Detector] (Thread-191) Using required_size=9 11:26:48 2016-09-11 11:24:27,433 WARNING [ProtocolDetector.Detector] (Thread-191) Unrecognized protocol: 'no such p' 11:26:48 2016-09-11 11:24:27,434 DEBUG [vds.MultiProtocolAcceptor] (MainThread) Stopping Acceptor 11:26:48 --------------------- >> end captured logging << --------------------- _______________________________________________ Devel mailing list Devel@ovirt.org http://lists.ovirt.org/mailman/listinfo/devel

Hopefully this [1] patch solves the issue. Thanks, Piotr [1] https://gerrit.ovirt.org/#/c/63685/ On Mon, Sep 12, 2016 at 12:23 PM, Piotr Kliczewski < piotr.kliczewski@gmail.com> wrote:
Will take a look.
On Mon, Sep 12, 2016 at 12:13 PM, Nir Soffer <nsoffer@redhat.com> wrote:
test_reject_concurrency(True) (protocoldetectorTests.AcceptorTests) fails once every few month.
Looks like a real issue in the actual code, doing double close. This is a known issue in asyncore that we already fixed in few places.
Nir
----
11:26:48 ============================================================ ========== 11:26:48 ERROR: test_reject_concurrency(True) (protocoldetectorTests.AcceptorTests) 11:26:48 ------------------------------------------------------------
11:26:48 Traceback (most recent call last): 11:26:48 File "/home/jenkins/workspace/vdsm_master_check-patch-fc24-x86_64/vdsm/tests/ protocoldetectorTests.py", line 113, in tearDown 11:26:48 self.acceptor.stop() 11:26:48 File "/home/jenkins/workspace/vdsm_master_check-patch-fc24-x86_ 64/vdsm/lib/vdsm/protocoldetector.py", line 211, in stop 11:26:48 self._acceptor.close() 11:26:48 File "/usr/lib64/python2.7/asyncore.py", line 407, in close 11:26:48 self.del_channel() 11:26:48 File "/home/jenkins/workspace/vdsm_master_check-patch-fc24-x86_ 64/vdsm/lib/yajsonrpc/betterAsyncore.py", line 137, in del_channel 11:26:48 asyncore.dispatcher.del_channel(self, map) 11:26:48 File "/usr/lib64/python2.7/asyncore.py", line 292, in del_channel 11:26:48 del map[fd] 11:26:48 KeyError: 63 11:26:48 -------------------- >> begin captured logging <<
11:26:48 2016-09-11 11:24:27,399 INFO [vds.MultiProtocolAcceptor] (MainThread) Listening at 127.0.0.1:46615 11:26:48 2016-09-11 11:24:27,399 DEBUG [vds.MultiProtocolAcceptor] (MainThread) Adding detector <protocoldetectorTests.Echo object at 0x7f03ee0b01d0> 11:26:48 2016-09-11 11:24:27,399 DEBUG [vds.MultiProtocolAcceptor] (MainThread) Adding detector <protocoldetectorTests.Uppercase object at 0x7f03ee0b0c50> 11:26:48 2016-09-11 11:24:27,402 INFO [ProtocolDetector.AcceptorImpl] (Thread-191) Accepting connection from 127.0.0.1:38136 11:26:48 2016-09-11 11:24:27,407 INFO [ProtocolDetector.AcceptorImpl] (Thread-191) Accepting connection from 127.0.0.1:38138 11:26:48 2016-09-11 11:24:27,411 INFO [ProtocolDetector.AcceptorImpl] (Thread-191) Accepting connection from 127.0.0.1:38140 11:26:48 2016-09-11 11:24:27,415 INFO [ProtocolDetector.AcceptorImpl] (Thread-191) Accepting connection from 127.0.0.1:38142 11:26:48 2016-09-11 11:24:27,416 DEBUG [ProtocolDetector.Detector] (Thread-191) Using required_size=9 11:26:48 2016-09-11 11:24:27,416 WARNING [vds.dispatcher] (Thread-191) unhandled write event 11:26:48 2016-09-11 11:24:27,420 INFO [ProtocolDetector.AcceptorImpl] (Thread-191) Accepting connection from 127.0.0.1:38144 11:26:48 2016-09-11 11:24:27,421 WARNING [ProtocolDetector.Detector] (Thread-191) Unrecognized protocol: 'no such p' 11:26:48 2016-09-11 11:24:27,427 DEBUG [ProtocolDetector.Detector] (Thread-191) Using required_size=9 11:26:48 2016-09-11 11:24:27,427 WARNING [vds.dispatcher] (Thread-191) unhandled write event 11:26:48 2016-09-11 11:24:27,428 DEBUG [ProtocolDetector.Detector] (Thread-191) Using required_size=9 11:26:48 2016-09-11 11:24:27,428 WARNING [vds.dispatcher] (Thread-191) unhandled write event 11:26:48 2016-09-11 11:24:27,429 WARNING [ProtocolDetector.Detector] (Thread-191) Unrecognized protocol: 'no such p' 11:26:48 2016-09-11 11:24:27,430 WARNING [ProtocolDetector.Detector] (Thread-191) Unrecognized protocol: 'no such p' 11:26:48 2016-09-11 11:24:27,430 DEBUG [ProtocolDetector.Detector] (Thread-191) Using required_size=9 11:26:48 2016-09-11 11:24:27,431 WARNING [ProtocolDetector.Detector] (Thread-191) Unrecognized protocol: 'no such p' 11:26:48 2016-09-11 11:24:27,433 DEBUG [ProtocolDetector.Detector] (Thread-191) Using required_size=9 11:26:48 2016-09-11 11:24:27,433 WARNING [ProtocolDetector.Detector] (Thread-191) Unrecognized protocol: 'no such p' 11:26:48 2016-09-11 11:24:27,434 DEBUG [vds.MultiProtocolAcceptor] (MainThread) Stopping Acceptor 11:26:48 --------------------- >> end captured logging <<
_______________________________________________ Devel mailing list Devel@ovirt.org http://lists.ovirt.org/mailman/listinfo/devel
participants (3)
-
Nir Soffer
-
Piotr Kliczewski
-
Piotr Kliczewski