New subject: [VDSM] VdsmClientTests.test_event_handler - flaky test?

12 Mar 2020

      I had 2 of these unrelated failures today. Would be nice to mark this
test as broken on CI.

https://jenkins.ovirt.org/job/vdsm_standard-check-patch/19353//artifact/chec...
https://jenkins.ovirt.org/job/vdsm_standard-check-patch/19354//artifact/chec...

=================================== FAILURES ===================================
______________________ VdsmClientTests.test_event_handler ______________________

self = <stomprpcclient_test.VdsmClientTests testMethod=test_event_handler>

    def test_event_handler(self):
        with self._create_client() as client:
            event_queue = queue.Queue()

            sub_id = client.subscribe(EVENT_TOPIC, event_queue)
...
client.Test.sendEvent()
lib/yajsonrpc/stomprpcclient_test.py:215:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <stomprpcclient_test._MockedClient object at 0x7fe19f6db1d0>
namespace = 'Test', method_name = 'sendEvent', kwargs = {}
method = 'Test.sendEvent', timeout = 3
req = {'jsonrpc': '2.0', 'method': 'Test.sendEvent', 'params': {},
'id': 'c3985771-6f77-4431-9ed6-15082063a2d5'}
responses = None

    def _call(self, namespace, method_name, **kwargs):
        """
        Client call method, executes a given command

        Args:
            namespace (string): namespace name
            method_name (string): method name
            **kwargs: Arbitrary keyword arguments

        Returns:
            method result

        Raises:
            ClientError: in case of an error in the protocol.
            TimeoutError: if there is no response after a pre configured time.
            ServerError: in case of an error while executing the command
        """
        method = namespace + "." + method_name
        timeout = kwargs.pop("_timeout", self._default_timeout)

        req = yajsonrpc.JsonRpcRequest(
            method, kwargs, reqId=str(uuid.uuid4()))

        try:
            responses = self._client.call(
                req, timeout=timeout, flow_id=self._flow_id)
        except EnvironmentError as e:
            raise ClientError(method, kwargs, e)

        if not responses:
...
raise TimeoutError(method, kwargs, timeout)
E           vdsm.client.TimeoutError: Request Test.sendEvent with args
{} timed out after 3 seconds

../lib/vdsm/client.py:294: TimeoutError
------------------------------ Captured log call -------------------------------
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled read event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled write event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled read event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled write event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled read event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled write event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled read event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled write event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled read event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled write event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled read event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled write event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled read event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled write event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled read event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled write event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled read event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled write event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled read event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled write event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled read event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled write event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled read event
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled write event
ERROR    vds.dispatcher:betterAsyncore.py:179 uncaptured python
exception, closing channel <yajsonrpc.betterAsyncore.Dispatcher
('::1', 36398, 0, 0) at 0x7fe19f6db208> (<class
'ValueError'>:'b'ept-version:1.2'' contains illegal character ':'
[/usr/lib64/python3.6/asyncore.py|readwrite|108]
[/usr/lib64/python3.6/asyncore.py|handle_read_event|423]
[/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/betterAsyncore.py|handle_read|71]
[/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/betterAsyncore.py|_delegate_call|168]
[/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/protocoldetector.py|handle_read|129]
[/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/stompserver.py|handle_socket|413]
[/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/rpc/bindingjsonrpc.py|add_socket|54]
[/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/stompserver.py|createListener|379]
[/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/stompserver.py|StompListener|345]
[/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/betterAsyncore.py|__init__|47]
[/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/betterAsyncore.py|switch_implementation|86]
[/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/stompserver.py|init|363]
[/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/rpc/bindingjsonrpc.py|_onAccept|57]
[/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/stomp.py|set_message_handler|645]
[/usr/lib64/python3.6/asyncore.py|handle_read_event|423]
[/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/betterAsyncore.py|handle_read|71]
[/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/betterAsyncore.py|_delegate_call|168]
[/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/stomp.py|handle_read|421]
[/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/stomp.py|parse|323]
[/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/stomp.py|_parse_command|245]
[/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/stomp.py|decode_value|167])
WARNING  vds.dispatcher:betterAsyncore.py:179 unhandled close event
ERROR    root:concurrent.py:267 FINISH thread <Thread(JsonRpc
(StompReactor), started daemon 140606575712000)> failed
Traceback (most recent call last):
  File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/common/concurrent.py",
line 260, in run
    ret = func(*args, **kwargs)
  File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/stompserver.py",
line 393, in process_requests
    self._reactor.process_requests()
  File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/betterAsyncore.py",
line 238, in process_requests
    timeout=self._get_timeout(self._map),
  File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/betterAsyncore.py",
line 253, in _get_timeout
    interval = disp.next_check_interval()
  File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/betterAsyncore.py",
line 99, in next_check_interval
    return getattr(self.__impl, "next_check_interval", default_func)()
  File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/stomp.py",
line 486, in next_check_interval
    self.handle_timeout()
  File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/stomp.py",
line 451, in handle_timeout
    self._frame_handler.handle_timeout(self)
  File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/stompclient.py",
line 130, in handle_timeout
    dispatcher._on_timeout)
  File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/stomp.py",
line 630, in reconnect
    AsyncDispatcher(self, self._async_client, count=count))
  File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/betterAsyncore.py",
line 271, in reconnect
    dispatcher.create_socket(address, sslctx)
  File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/betterAsyncore.py",
line 112, in create_socket
    sock = sslctx.wrapSocket(sock)
  File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/sslutils.py",
line 113, in wrapSocket
    ca_certs=self.ca_certs)
  File "/usr/lib64/python3.6/ssl.py", line 1114, in wrap_socket
    ciphers=ciphers)
  File "/usr/lib64/python3.6/ssl.py", line 704, in __init__
    self._context.load_verify_locations(ca_certs)
FileNotFoundError: [Errno 2] No such file or directory
=============================== warnings summary ===============================
/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/.tox/lib/lib/python3.6/site-packages/_pytest/mark/structures.py:334
  /home/jenkins/workspace/vdsm_standard-check-patch/vdsm/.tox/lib/lib/python3.6/site-packages/_pytest/mark/structures.py:334:
PytestUnknownMarkWarning: Unknown pytest.mark.stress - is this a typo?
 You can register custom marks to avoid this warning - for details,
see https://docs.pytest.org/en/latest/mark.html
    PytestUnknownMarkWarning,

/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/.tox/lib/lib/python3.6/site-packages/_pytest/mark/structures.py:334
  /home/jenkins/workspace/vdsm_standard-check-patch/vdsm/.tox/lib/lib/python3.6/site-packages/_pytest/mark/structures.py:334:
PytestUnknownMarkWarning: Unknown pytest.mark.slow - is this a typo?
You can register custom marks to avoid this warning - for details, see
https://docs.pytest.org/en/latest/mark.html
    PytestUnknownMarkWarning,

/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/v2v.py:79
  /home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/v2v.py:79:
DeprecationWarning: invalid escape sequence \d
    _SSH_AUTH_RE = b'(SSH_AUTH_SOCK)=([^;]+).*;\nSSH_AGENT_PID=(\d+)'

/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/v2v.py:1421
  /home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/v2v.py:1421:
DeprecationWarning: invalid escape sequence \^
    '(?P<m2_base>[0-9]+){sp}\^{sp}(?P<m2_exp>{exp}))'.format(

/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/.tox/lib/lib/python3.6/site-packages/_pytest/mark/structures.py:334
  /home/jenkins/workspace/vdsm_standard-check-patch/vdsm/.tox/lib/lib/python3.6/site-packages/_pytest/mark/structures.py:334:
PytestUnknownMarkWarning: Unknown pytest.mark.xpass - is this a typo?
You can register custom marks to avoid this warning - for details, see
https://docs.pytest.org/en/latest/mark.html
    PytestUnknownMarkWarning,

tests/lib/osinfo_test.py::test_package_versions
  /home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/osinfo.py:284:
UnicodeWarning: decode() called on unicode string, see
https://bugzilla.redhat.com/show_bug.cgi?id=1693751
    'version': mi['version'].decode('utf-8'),

tests/lib/osinfo_test.py::test_package_versions
  /home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/vdsm/osinfo.py:285:
UnicodeWarning: decode() called on unicode string, see
https://bugzilla.redhat.com/show_bug.cgi?id=1693751
    'release': mi['release'].decode('utf-8'),

-- Docs: https://docs.pytest.org/en/latest/warnings.html

----------- coverage: platform linux, python 3.6.8-final-0 -----------
Coverage HTML written to dir htmlcov-lib

========================== slowest 10 test durations ===========================
18.29s call
tests/lib/yajsonrpc/stomprpcclient_test.py::VdsmClientTests::test_event_handler
2.96s call     tests/lib/protocoldetector_test.py::AcceptorTests::test_reject_very_slow_client_concurrency(True)
2.90s call     tests/lib/protocoldetector_test.py::AcceptorTests::test_reject_very_slow_client_concurrency(False)
2.75s call     tests/lib/protocoldetector_test.py::AcceptorTests::test_reject_very_slow_client(False)
2.63s call     tests/lib/protocoldetector_test.py::AcceptorTests::test_reject_very_slow_client(True)
1.90s call     tests/pywatch_test.py::TestPyWatch::test_timeout_backtrace
1.44s call     tests/pywatch_test.py::TestPyWatch::test_timeout_output
1.19s call     tests/pywatch_test.py::TestPyWatch::test_kill_grandkids
0.93s call     tests/lib/protocoldetector_test.py::AcceptorTests::test_detect_slow_client(True)
0.90s call     tests/lib/yajsonrpc/stomp_test.py::StompTests::test_echo(16384,
False)
=========================== short test summary info ============================

[VDSM] VdsmClientTests.test_event_handler - flaky test?

Nir Soffer

Nir Soffer

Nir Soffer

Nir Soffer

Marcin Sobczyk

Nir Soffer

Marcin Sobczyk

Martin Perina

Nir Soffer

Nir Soffer

tags

participants (3)