On Wed, Nov 7, 2018 at 2:20 PM Piotr Kliczewski <[email protected]> wrote:
>
>
> On Wed, Nov 7, 2018 at 1:16 PM Nir Soffer <[email protected]> wrote:
>
>> On Wed, Nov 7, 2018 at 10:13 AM Piotr Kliczewski <[email protected]>
>> wrote:
>>
>>>
>>>
>>> On Wed, Nov 7, 2018 at 5:21 AM Germano Veit Michel <[email protected]>
>>> wrote:
>>>
>>>>
>>>> On Sat, Jun 30, 2018 at 12:43 AM Piotr Kliczewski <
>>>> [email protected]> wrote:
>>>>
>>>>> Here is the patch [1] which should fix it.
>>>>>
>>>>> [1] https://gerrit.ovirt.org/#/c/92690/
>>>>> On Thu, Jun 28, 2018 at 2:44 PM Piotr Kliczewski <[email protected]>
>>>>> wrote:
>>>>> >
>>>>> > Nir,
>>>>> >
>>>>> > It looks like we have a race condition where request arrive sooner
>>>>> than subscribe frame:
>>>>> >
>>>>> > 16:19:02 2018-06-27 14:17:54,653 INFO (jsonrpc/0)
>>>>> [jsonrpc.JsonRpcServer] RPC call echo succeeded in 0.01 seconds
>>>>> (__init__:311)
>>>>> > 16:19:02 2018-06-27 14:17:54,661 INFO (Detector thread)
>>>>> [Broker.StompAdapter] Subscribe command received (stompserver:123)
>>>>> >
>>>>> > Thanks for reporting I will push a patch to fix it.
>>>>> >
>>>>> > Thanks,
>>>>> > Piotr
>>>>> >
>>>>> >
>>>>> > On Wed, Jun 27, 2018 at 5:40 PM, Piotr Kliczewski <
>>>>> [email protected]> wrote:
>>>>> >>
>>>>> >> Ok, I'll take a look.
>>>>> >>
>>>>> >> śr., 27 cze 2018, 17:36 użytkownik Nir Soffer <[email protected]>
>>>>> napisał:
>>>>> >>>
>>>>> >>> On Wed, Jun 27, 2018 at 6:13 PM Piotr Kliczewski <
>>>>> [email protected]> wrote:
>>>>> >>>>
>>>>> >>>> On Wed, Jun 27, 2018 at 5:01 PM, Nir Soffer <[email protected]>
>>>>> wrote:
>>>>> >>>>>
>>>>> >>>>> This tests used to fail in the past, but since we fixed it or
>>>>> the code
>>>>> >>>>>
>>>>> >>>>> it never failed.
>>>>> >>>>>
>>>>> >>>>>
>>>>> >>>>> Maybe the slave was overloaded?
>>>>> >>>>
>>>>> >>>>
>>>>> >>>> Very possible. Can you paste a link to the job which failed?
>>>>> >>>
>>>>> >>>
>>>>> >>> Here:
>>>>> https://jenkins.ovirt.org/job/vdsm_master_check-patch-el7-x86_64/24130/
>>>>> >>>
>>>>> >>> The next build passed.
>>>>> >>>
>>>>> >>> Maybe we need to solve the flakiness of some tests by running a
>>>>> flaky test
>>>>> >>> again, and let the build fail only if a test failed twice. I
>>>>> wonder if there is some
>>>>> >>> pytest plugin doing this.
>>>>> >>>
>>>>> >>>>
>>>>> >>>>
>>>>> >>>>>
>>>>> >>>>>
>>>>> >>>>> 14:19:02
>>>>> ======================================================================
>>>>> >>>>> 14:19:02 ERROR:
>>>>> >>>>>
>>>>> >>>>> 14:19:02
>>>>> ----------------------------------------------------------------------
>>>>> >>>>> 14:19:02 Traceback (most recent call last):
>>>>> >>>>> 14:19:02 File
>>>>> "/home/jenkins/workspace/vdsm_master_check-patch-el7-x86_64/vdsm/tests/testlib.py",
>>>>> line 143, in wrapper
>>>>> >>>>> 14:19:02 return f(self, *args)
>>>>> >>>>> 14:19:02 File
>>>>> "/home/jenkins/workspace/vdsm_master_check-patch-el7-x86_64/vdsm/tests/stomp_test.py",
>>>>> line 95, in test_echo
>>>>> >>>>> 14:19:02 str(uuid4())),
>>>>> >>>>> 14:19:02 File
>>>>> "/home/jenkins/workspace/vdsm_master_check-patch-el7-x86_64/vdsm/lib/yajsonrpc/jsonrpcclient.py",
>>>>> line 77, in callMethod
>>>>> >>>>> 14:19:02 raise
>>>>> exception.JsonRpcNoResponseError(method=methodName)
>>>>> >>>>> 14:19:02 JsonRpcNoResponseError: No response for JSON-RPC
>>>>> request: {'method': 'echo'}
>>>>> >>>>> 14:19:02 -------------------- >> begin captured logging <<
>>>>> --------------------
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,524 DEBUG (MainThread)
>>>>> [vds.MultiProtocolAcceptor] Creating socket (host='::1', port=0,
>>>>> family=10,
>>>>> socketype=1, proto=6) (protocoldetector:225)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,526 INFO (MainThread)
>>>>> [vds.MultiProtocolAcceptor] Listening at ::1:36713 (protocoldetector:183)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,535 DEBUG (MainThread) [Scheduler]
>>>>> Starting scheduler test.Scheduler (schedule:98)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,537 DEBUG (test.Scheduler)
>>>>> [Scheduler] START thread <Thread(test.Scheduler, started daemon
>>>>> 140562082535168)> (func=<bound method Scheduler._run of
>>>>> <vdsm.schedule.Scheduler object at 0x7fd74ca00390>>, args=(), kwargs={})
>>>>> (concurrent:193)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,538 DEBUG (test.Scheduler)
>>>>> [Scheduler] started (schedule:140)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,546 DEBUG (JsonRpc (StompReactor))
>>>>> [root] START thread <Thread(JsonRpc (StompReactor), started daemon
>>>>> 140562629256960)> (func=<bound method StompReactor.process_requests of
>>>>> <yajsonrpc.stompserver.StompReactor object at 0x7fd74ca006d0>>, args=(),
>>>>> kwargs={}) (concurrent:193)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,547 DEBUG (MainThread) [Executor]
>>>>> Starting executor (executor:128)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,549 DEBUG (MainThread) [Executor]
>>>>> Starting worker jsonrpc/0 (executor:286)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,553 DEBUG (jsonrpc/0) [Executor]
>>>>> START thread <Thread(jsonrpc/0, started daemon 140562612471552)>
>>>>> (func=<bound method _Worker._run of <Worker name=jsonrpc/0 waiting task#=0
>>>>> at 0x7fd74ca00650>>, args=(), kwargs={}) (concurrent:193)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,554 DEBUG (jsonrpc/0) [Executor]
>>>>> Worker started (executor:298)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,557 DEBUG (MainThread) [Executor]
>>>>> Starting worker jsonrpc/1 (executor:286)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,558 DEBUG (MainThread) [Executor]
>>>>> Starting worker jsonrpc/2 (executor:286)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,559 DEBUG (jsonrpc/2) [Executor]
>>>>> START thread <Thread(jsonrpc/2, started daemon 140562620864256)>
>>>>> (func=<bound method _Worker._run of <Worker name=jsonrpc/2 waiting task#=0
>>>>> at 0x7fd74c9fb350>>, args=(), kwargs={}) (concurrent:193)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,560 DEBUG (jsonrpc/2) [Executor]
>>>>> Worker started (executor:298)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,561 DEBUG (MainThread) [Executor]
>>>>> Starting worker jsonrpc/3 (executor:286)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,562 DEBUG (jsonrpc/3) [Executor]
>>>>> START thread <Thread(jsonrpc/3, started daemon 140562124498688)>
>>>>> (func=<bound method _Worker._run of <Worker name=jsonrpc/3 waiting task#=0
>>>>> at 0x7fd74bc80290>>, args=(), kwargs={}) (concurrent:193)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,563 DEBUG (jsonrpc/3) [Executor]
>>>>> Worker started (executor:298)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,564 DEBUG (MainThread) [Executor]
>>>>> Starting worker jsonrpc/4 (executor:286)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,565 DEBUG (jsonrpc/4) [Executor]
>>>>> START thread <Thread(jsonrpc/4, started daemon 140562116105984)>
>>>>> (func=<bound method _Worker._run of <Worker name=jsonrpc/4 waiting task#=0
>>>>> at 0x7fd74bc80790>>, args=(), kwargs={}) (concurrent:193)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,566 DEBUG (jsonrpc/4) [Executor]
>>>>> Worker started (executor:298)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,568 DEBUG (jsonrpc/1) [Executor]
>>>>> START thread <Thread(jsonrpc/1, started daemon 140562132891392)>
>>>>> (func=<bound method _Worker._run of <Worker name=jsonrpc/1 waiting task#=0
>>>>> at 0x7fd74c9fb690>>, args=(), kwargs={}) (concurrent:193)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,569 DEBUG (jsonrpc/1) [Executor]
>>>>> Worker started (executor:298)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,569 DEBUG (MainThread) [Executor]
>>>>> Starting worker jsonrpc/5 (executor:286)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,570 DEBUG (jsonrpc/5) [Executor]
>>>>> START thread <Thread(jsonrpc/5, started daemon 140562107713280)>
>>>>> (func=<bound method _Worker._run of <Worker name=jsonrpc/5 waiting task#=0
>>>>> at 0x7fd74bc80090>>, args=(), kwargs={}) (concurrent:193)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,571 DEBUG (jsonrpc/5) [Executor]
>>>>> Worker started (executor:298)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,572 DEBUG (MainThread) [Executor]
>>>>> Starting worker jsonrpc/6 (executor:286)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,580 DEBUG (MainThread) [Executor]
>>>>> Starting worker jsonrpc/7 (executor:286)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,603 DEBUG (jsonrpc/6) [Executor]
>>>>> START thread <Thread(jsonrpc/6, started daemon 140562099320576)>
>>>>> (func=<bound method _Worker._run of <Worker name=jsonrpc/6 waiting task#=0
>>>>> at 0x7fd74d0dacd0>>, args=(), kwargs={}) (concurrent:193)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,604 DEBUG (jsonrpc/6) [Executor]
>>>>> Worker started (executor:298)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,615 DEBUG (jsonrpc/7) [Executor]
>>>>> START thread <Thread(jsonrpc/7, started daemon 140562090927872)>
>>>>> (func=<bound method _Worker._run of <Worker name=jsonrpc/7 waiting task#=0
>>>>> at 0x7fd74bfe0310>>, args=(), kwargs={}) (concurrent:193)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,616 DEBUG (JsonRpcServer) [root]
>>>>> START thread <Thread(JsonRpcServer, started daemon 140561730238208)>
>>>>> (func=<bound method JsonRpcServer.serve_requests of
>>>>> <yajsonrpc.JsonRpcServer object at 0x7fd74ca00690>>, args=(), kwargs={})
>>>>> (concurrent:193)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,618 DEBUG (MainThread)
>>>>> [vds.MultiProtocolAcceptor] Adding detector
>>>>> <yajsonrpc.stompserver.StompDetector instance at 0x7fd74c28cc68>
>>>>> (protocoldetector:210)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,625 INFO (Detector thread)
>>>>> [ProtocolDetector.AcceptorImpl] Accepted connection from ::1:52432
>>>>> (protocoldetector:61)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,626 DEBUG (Detector thread)
>>>>> [ProtocolDetector.Detector] Using required_size=11 (protocoldetector:89)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,627 DEBUG (jsonrpc/7) [Executor]
>>>>> Worker started (executor:298)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,634 DEBUG (MainThread)
>>>>> [jsonrpc.AsyncoreClient] Sending response (stompclient:293)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,634 DEBUG (Client ::1:36713) [root]
>>>>> START thread <Thread(Client ::1:36713, started daemon 140561713452800)>
>>>>> (func=<bound method Reactor.process_requests of
>>>>> <yajsonrpc.betterAsyncore.Reactor object at 0x7fd74bdb1d90>>, args=(),
>>>>> kwargs={}) (concurrent:193)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,641 INFO (Detector thread)
>>>>> [ProtocolDetector.Detector] Detected protocol stomp from ::1:52432
>>>>> (protocoldetector:125)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,645 INFO (Detector thread)
>>>>> [Broker.StompAdapter] Processing CONNECT request (stompserver:94)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,648 DEBUG (Client ::1:36713)
>>>>> [yajsonrpc.protocols.stomp.AsyncClient] Stomp connection established
>>>>> (stompclient:137)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,651 DEBUG (jsonrpc/0)
>>>>> [jsonrpc.JsonRpcServer] Calling 'echo' in bridge with [u'Lorem ipsum dolor
>>>>> sit amet, consectetur adipisicing elit, sed do eiusmod tempor incididunt
>>>>> ut
>>>>> labore et dolore magna aliqua. Ut enim ad minim veniam, quis nostrud
>>>>> exercitation ullamco laboris nisi ut aliquip ex ea commodo consequat. Duis
>>>>> aute irure dolor in reprehenderit in voluptate velit esse cillum dolore eu
>>>>> fugiat nulla pariatur. Excepteur sint occaecat cupidatat non proident,
>>>>> sunt
>>>>> in culpa qui officia deserunt mollit anim id est laborum. Lorem ipsum
>>>>> dolor
>>>>> sit amet, consectetur adipisicing elit, sed do eiusmod tempor incididunt
>>>>> ut
>>>>> labore et dolore magna aliqua. Ut enim ad minim veniam, quis nostrud
>>>>> exercitation ullamco laboris nisi ut aliquip ex ea commodo consequat. Duis
>>>>> aute irure dolor in reprehenderit in voluptate velit esse cillum dolore eu
>>>>> fugiat nulla pariatur. Excepteur sint occaecat cupidatat non proident,
>>>>> sunt
>>>>> in culpa qui officia deserunt mollit anim id est laborum. Lorem ipsum
>>>>> dolor
>>>>> sit amet, consectetur adipisicing elit, sed do eiusmod tempor incididunt
>>>>> ut
>>>>> labore et dolore magna aliqua. Ut en'] (__init__:328)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,652 DEBUG (jsonrpc/0)
>>>>> [jsonrpc.JsonRpcServer] Return 'echo' in bridge with Lorem ipsum dolor sit
>>>>> amet, consectetur adipisicing elit, sed do eiusmod tempor incididunt ut
>>>>> labore et dolore magna aliqua. Ut enim ad minim veniam, quis nostrud
>>>>> exercitation ullamco laboris nisi ut aliquip ex ea commodo consequat. Duis
>>>>> aute irure dolor in reprehenderit in voluptate velit esse cillum dolore eu
>>>>> fugiat nulla pariatur. Excepteur sint occaecat cupidatat non proident,
>>>>> sunt
>>>>> in culpa qui officia deserunt mollit anim id est laborum. Lorem ipsum
>>>>> dolor
>>>>> sit amet, consectetur adipisicing elit, sed do eiusmod tempor incididunt
>>>>> ut
>>>>> labore et dolore magna aliqua. Ut enim ad minim veniam, quis nostrud
>>>>> exercitation ullamco laboris nisi ut aliquip ex ea commodo consequat. Duis
>>>>> aute irure dolor in reprehenderit in voluptate velit esse cillum dolore eu
>>>>> fugiat nulla pariatur. Excepteur sint occaecat cupidatat non proident,
>>>>> sunt
>>>>> in culpa qui officia deserunt mollit anim id est laborum. Lorem ipsum
>>>>> dolor
>>>>> sit amet, consectetur adipisicing elit, sed do eiusmod tempor incididunt
>>>>> ut
>>>>> labore et dolore magna aliqua. Ut en (__init__:355)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,653 INFO (jsonrpc/0)
>>>>> [jsonrpc.JsonRpcServer] RPC call echo succeeded in 0.01 seconds
>>>>> (__init__:311)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,661 INFO (Detector thread)
>>>>> [Broker.StompAdapter] Subscribe command received (stompserver:123)
>>>>> >>>>> 14:19:02 2018-06-27 14:17:54,662 DEBUG (Detector thread)
>>>>> [protocoldetector.StompDetector] Stomp detected from ('::1', 52432)
>>>>> (stompserver:412)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,649 DEBUG (MainThread)
>>>>> [vds.MultiProtocolAcceptor] Stopping Acceptor (protocoldetector:214)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,650 INFO (MainThread)
>>>>> [jsonrpc.JsonRpcServer] Stopping JsonRPC Server (__init__:441)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,651 DEBUG (MainThread) [Executor]
>>>>> Stopping executor (executor:137)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,652 DEBUG (Client ::1:36713) [root]
>>>>> FINISH thread <Thread(Client ::1:36713, started daemon 140561713452800)>
>>>>> (concurrent:196)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,652 DEBUG (JsonRpcServer) [root]
>>>>> FINISH thread <Thread(JsonRpcServer, started daemon 140561730238208)>
>>>>> (concurrent:196)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,654 DEBUG (JsonRpc (StompReactor))
>>>>> [root] FINISH thread <Thread(JsonRpc (StompReactor), started daemon
>>>>> 140562629256960)> (concurrent:196)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,655 DEBUG (jsonrpc/2) [Executor]
>>>>> Worker stopped (executor:303)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,658 DEBUG (jsonrpc/3) [Executor]
>>>>> Worker stopped (executor:303)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,659 DEBUG (jsonrpc/4) [Executor]
>>>>> Worker stopped (executor:303)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,660 DEBUG (jsonrpc/1) [Executor]
>>>>> Worker stopped (executor:303)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,660 DEBUG (jsonrpc/5) [Executor]
>>>>> Worker stopped (executor:303)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,660 DEBUG (jsonrpc/6) [Executor]
>>>>> Worker stopped (executor:303)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,665 DEBUG (jsonrpc/6) [Executor]
>>>>> FINISH thread <Thread(jsonrpc/6, started daemon 140562099320576)>
>>>>> (concurrent:196)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,661 DEBUG (jsonrpc/7) [Executor]
>>>>> Worker stopped (executor:303)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,662 DEBUG (jsonrpc/2) [Executor]
>>>>> FINISH thread <Thread(jsonrpc/2, started daemon 140562620864256)>
>>>>> (concurrent:196)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,663 DEBUG (jsonrpc/3) [Executor]
>>>>> FINISH thread <Thread(jsonrpc/3, started daemon 140562124498688)>
>>>>> (concurrent:196)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,663 DEBUG (jsonrpc/1) [Executor]
>>>>> FINISH thread <Thread(jsonrpc/1, started daemon 140562132891392)>
>>>>> (concurrent:196)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,664 DEBUG (jsonrpc/4) [Executor]
>>>>> FINISH thread <Thread(jsonrpc/4, started daemon 140562116105984)>
>>>>> (concurrent:196)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,664 DEBUG (jsonrpc/0) [Executor]
>>>>> Worker stopped (executor:303)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,665 DEBUG (jsonrpc/5) [Executor]
>>>>> FINISH thread <Thread(jsonrpc/5, started daemon 140562107713280)>
>>>>> (concurrent:196)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,667 DEBUG (jsonrpc/7) [Executor]
>>>>> FINISH thread <Thread(jsonrpc/7, started daemon 140562090927872)>
>>>>> (concurrent:196)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,667 DEBUG (MainThread) [Executor]
>>>>> Waiting for worker jsonrpc/0 (executor:290)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,671 DEBUG (jsonrpc/0) [Executor]
>>>>> FINISH thread <Thread(jsonrpc/0, started daemon 140562612471552)>
>>>>> (concurrent:196)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,673 DEBUG (MainThread) [Executor]
>>>>> Waiting for worker jsonrpc/1 (executor:290)
>>>>> >>>>> 14:19:02 2018-06-27 14:18:09,674 DEBUG (MainThread) [Executor]
>>>>> Waiting for worker jsonrpc/6 (executor:290)
>>>>> >>>>> 14:19:02 2018-Coverage.py warning: Module
>>>>> /home/jenkins/workspace/vdsm_master_check-patch-el7-x86_64/vdsm/vdsm was
>>>>> never imported. (module-not-imported)
>>>>> >>>>> 14:19:05 pylint installdeps: pylint==1.8
>>>>> >>>>> 14:19:22 pylint installed: The directory
>>>>> '/home/jenkins/workspace/vdsm_master_check-patch-el7-x86_64/vdsm/.cache/pip/http'
>>>>> or its parent directory is not owned by the current user and the cache has
>>>>> been disabled. Please check the permissions and owner of that directory.
>>>>> If
>>>>> executing pip with sudo, you may want sudo's -H
>>>>> flag.,astroid==1.6.5,backports.functools-lru-cache==1.5,backports.ssl-match-hostname==3.5.0.1,blivet==0.61.15.69,chardet==2.2.1,configparser==3.5.0,coverage==4.4.1,decorator==3.4.0,enum34==1.1.6,funcsigs==1.0.2,futures==3.2.0,iniparse==0.4,ioprocess==1.1.0,ipaddress==1.0.16,IPy==0.75,isort==4.3.4,kitchen==1.1.1,lazy-object-proxy==1.3.1,libvirt-python==3.9.0,Magic-file-extensions==0.2,mccabe==0.6.1,mock==2.0.0,netaddr==0.7.18,ovirt-imageio-common==1.4.1,pbr==3.1.1,pluggy==0.6.0,policycoreutils-default-encoding==0.1,pthreading==0.1.3,py==1.5.4,pycurl==7.19.0,pygpgme==0.3,pyinotify==0.9.4,pykickstart==1.99.66.18,pyliblzma==0.5.3,pylint==1.8.0,pyparted==3.9,python-augeas==0.5.0,python-dateutil==2.4.2,pyudev==0.15,pyxattr==0.5.1,PyYAML==3.10,requests==2.6.0,sanlock-python==3.6.0,seobject==0.1,sepolicy==1.1,singledispatch==3.4.0.3,six==1.11.0,subprocess32==3.2.6,tox==2.9.1,urlgrabber==3.10,urllib3==1.10.2,virtualenv==16.0.0,WebOb==1.2.3,wrapt==1.10.11,yum-metadata-parser==1.1.4
>>>>> >>>>> 14:19:22 pylint runtests: PYTHONHASHSEED='528910716'
>>>>> >>>>> 14:19:22 pylint runtests: commands[0] | pylint --errors-only
>>>>> static/usr/share/vdsm/sitecustomize.py lib/vdsm lib/vdsmclient
>>>>> lib/yajsonrpc
>>>>> >>>>> 14:19:23 Problem importing module base.pyc: cannot import name
>>>>> get_node_last_lineno
>>>>> >>>>> 14:19:24 Problem importing module base.py: cannot import name
>>>>> get_node_last_lineno
>>>>> >>>>> 14:19:34 06-27 14:18:09,674 DEBUG (MainThread) [Executor]
>>>>> Waiting for worker jsonrpc/7 (executor:290)
>>>>> >>>>> 14:19:34 2018-06-27 14:18:09,675 DEBUG (MainThread) [Executor]
>>>>> Waiting for worker jsonrpc/5 (executor:290)
>>>>> >>>>> 14:19:34 2018-06-27 14:18:09,675 DEBUG (MainThread) [Executor]
>>>>> Waiting for worker jsonrpc/2 (executor:290)
>>>>> >>>>> 14:19:34 2018-06-27 14:18:09,676 DEBUG (MainThread) [Executor]
>>>>> Waiting for worker jsonrpc/3 (executor:290)
>>>>> >>>>> 14:19:34 2018-06-27 14:18:09,676 DEBUG (MainThread) [Executor]
>>>>> Waiting for worker jsonrpc/4 (executor:290)
>>>>> >>>>> 14:19:34 2018-06-27 14:18:09,677 DEBUG (MainThread) [Scheduler]
>>>>> Stopping scheduler test.Scheduler (schedule:110)
>>>>> >>>>> 14:19:34 2018-06-27 14:18:09,678 DEBUG (test.Scheduler)
>>>>> [Scheduler] stopped (schedule:143)
>>>>> >>>>> 14:19:34 2018-06-27 14:18:09,679 DEBUG (test.Scheduler)
>>>>> [Scheduler] FINISH thread <Thread(test.Scheduler, started daemon
>>>>> 140562082535168)> (concurrent:196)
>>>>> >>>>> 14:19:34 --------------------- >> end captured logging <<
>>>>> ---------------------
>>>>> >>>>>
>>>>> >>>>>
>>>>> >
>>>>> > _______________________________________________
>>>>> > Devel mailing list -- [email protected]
>>>>> > To unsubscribe send an email to [email protected]
>>>>> > Privacy Statement: https://www.ovirt.org/site/privacy-policy/
>>>>> > oVirt Code of Conduct:
>>>>> https://www.ovirt.org/community/about/community-guidelines/
>>>>> > List Archives:
>>>>> https://lists.ovirt.org/archives/list/[email protected]/message/ACPGZ4N3ULQ6GJNEGJCYJ6NASDHRYNYL/
>>>>> _______________________________________________
>>>>> Devel mailing list -- [email protected]
>>>>> To unsubscribe send an email to [email protected]
>>>>> Privacy Statement: https://www.ovirt.org/site/privacy-policy/
>>>>> oVirt Code of Conduct:
>>>>> https://www.ovirt.org/community/about/community-guidelines/
>>>>> List Archives:
>>>>> https://lists.ovirt.org/archives/list/[email protected]/message/IJJZC7GEB2JMFKR2CXLYH33XGRI7M6EF/
>>>>
>>>>
>>>> Sorry to bring this back, I see Piotr patch was not merged and the
>>>> problem still happens. Just hit it on latest master on fc28:
>>>>
>>>> https://jenkins.ovirt.org/job/vdsm_master_check-patch-fc28-x86_64/1808/artifact/exported-artifacts/mock_logs/script/stdout_stderr.log
>>>>
>>>> When submitting longer series of patches, these random errors are
>>>> really annoying as 1 or 2 patches always fail. Then submit again and some
>>>> other patch fails...
>>>>
>>>
>>> I rebased the patch. @Nir, @Milan, @Marcin Please review
>>>
>>
>> I don't think this is the right approach. This does not fix the root cause
>> but cover it by playing with order of messages.
>>
>
> Please read the thread again and you will see why the order matters here.
>
I agree that the order matters, however the issue is not in the client, and
putting
SUBSCRIBE frames on the start of the outbox queue will not help:
https://gerrit.ovirt.org/c/92690/
The issue is having 2 reactor threads on the server side, and passing a
socket
from one reactor to the other.
After I added (temporary) debug logs in both server and clients
https://gerrit.ovirt.org/c/95895
We see that the client always send CONNECT and SUBSCRIBE frames
in the correct order.
[check-patch.el7.x86_64] 2018-11-30 23:11:39,073 DEBUG (Client ::1:44347)
[stomp.AsyncDispatcher] handle_write: sending
'CONNECT\naccept-version:1.2\nheart-beat:0,24000\n\n\x00' (stomp:500)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,078 DEBUG (Client ::1:44347)
[stomp.AsyncDispatcher] handle_write: sending
'SUBSCRIBE\nack:auto\ndestination:00397ca9-7f39-4602-b115-7ce5bd06a6dd\nid:947a595d-d086-4c48-a0e9-587b42abc6f2\n\n\x00'
(stomp:500)
On the server side, we see that both frames are received by the acceptor
thread
in handle_read:
[check-patch.el7.x86_64] 2018-11-30 23:11:39,081 DEBUG (Detector thread)
[stomp.AsyncDispatcher] handle_read: received data:
'CONNECT\naccept-version:1.2\nheart-beat:0,24000\n\n\x00SUBSCRIBE\nack:auto\ndestination:00397ca9-7f39-4602-b115-7ce5bd06a6dd\nid:947a595d-d086-4c48-a0e9-587b42abc6f2\n\n\x00'
(stomp:412)
And then the server parse the frames and handle both in the loop in
handle_read:
[check-patch.el7.x86_64] 2018-11-30 23:11:39,081 DEBUG (Detector thread)
[stomp.AsyncDispatcher] handle_read: handling frame: <StompFrame
command=u'CONNECT'> (stomp:418)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,081 INFO (Detector thread)
[Broker.StompAdapter] Processing CONNECT request (stompserver:95)
This send a CONNECTED frame to the client, and it received it:
[check-patch.el7.x86_64] 2018-11-30 23:11:39,083 DEBUG (Client ::1:44347)
[stomp.AsyncDispatcher] handle_read: received data:
'CONNECTED\nversion:1.2\nheart-beat:24000,0\n\n\x00' (stomp:412)
Now the server acceptor thread run again and handle the SUBSCRIBE frame:
[check-patch.el7.x86_64] 2018-11-30 23:11:39,086 DEBUG (Detector thread)
[stomp.AsyncDispatcher] handle_read: handling frame: <StompFrame
command=u'SUBSCRIBE'> (stomp:418)
But before it run the code registering the subscription, the client thread
run again and send the SEND frame:
[check-patch.el7.x86_64] 2018-11-30 23:11:39,088 DEBUG (Client ::1:44347)
[stomp.AsyncDispatcher] handle_write: sending
'SEND\nreply-to:00397ca9-7f39-4602-b115-7ce5bd06a6dd\ndestination:jms.topic.vdsm_requests\ncontent-type:application/json\ncontent-length:200\n\n[{"params":
["Lorem ipsum dolor sit amet, consectetur adipisicing elit, sed do eiusmod
tempor incididunt ut labore"], "jsonrpc": "2.0", "method": "echo", "id":
"4c11fd4d-de1a-48a3-9288-4d60a9556759"}]\x00' (stomp:500)
Now the jsonrpc reactor thread run before the acceptor thread and handle
the SEND frame:
[check-patch.el7.x86_64] 2018-11-30 23:11:39,089 DEBUG (JsonRpc
(StompReactor)) [stomp.AsyncDispatcher] handle_read: received data:
'SEND\nreply-to:00397ca9-7f39-4602-b115-7ce5bd06a6dd\ndestination:jms.topic.vdsm_requests\ncontent-type:application/json\ncontent-length:200\n\n[{"params":
["Lorem ipsum dolor sit amet, consectetur adipisicing elit, sed do eiusmod
tempor incididunt ut labore"], "jsonrpc": "2.0", "method": "echo", "id":
"4c11fd4d-de1a-48a3-9288-4d60a9556759"}]\x00' (stomp:412)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,089 DEBUG (JsonRpc
(StompReactor)) [stomp.AsyncDispatcher] handle_read: handling frame:
<StompFrame command=u'SEND'> (stomp:418)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,091 DEBUG (jsonrpc/0)
[jsonrpc.JsonRpcServer] Calling 'echo' in bridge with [u'Lorem ipsum dolor
sit amet, consectetur adipisicing elit, sed do eiusmod tempor incididunt ut
labore'] (__init__:329)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,091 DEBUG (jsonrpc/0)
[jsonrpc.JsonRpcServer] Return 'echo' in bridge with Lorem ipsum dolor sit
amet, consectetur adipisicing elit, sed do eiusmod tempor incididunt ut
labore (__init__:356)
Finally the acceptor thread run again and handles the SUBSCRIBE frame:
[check-patch.el7.x86_64] 2018-11-30 23:11:39,087 INFO (Detector thread)
[Broker.StompAdapter] Subscribe command received (stompserver:124)
But this is too late since the SEND frame already handled and without
subscription the response was dropped.
See the attached test failure log.
You can see the complete build log here:
https://jenkins.ovirt.org/job/vdsm_standard-check-patch/493/consoleFull
I posted an experimental fix:
https://gerrit.ovirt.org/c/95899
Now the build pass, running test_echo 1000 times. Previously we would get
about
2-3 failures for 1000 runs.
https://jenkins.ovirt.org/job/vdsm_standard-check-patch/497/consoleFull
Nir
>
[check-patch.el7.x86_64] ======================================================================
[check-patch.el7.x86_64] ERROR: test_echo('00026', 100, False) (stomp_test.StompTests)
[check-patch.el7.x86_64] ----------------------------------------------------------------------
[check-patch.el7.x86_64] Traceback (most recent call last):
[check-patch.el7.x86_64] File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/tests/testlib.py", line 143, in wrapper
[check-patch.el7.x86_64] return f(self, *args)
[check-patch.el7.x86_64] File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/tests/stomp_test.py", line 95, in test_echo
[check-patch.el7.x86_64] str(uuid4())),
[check-patch.el7.x86_64] File "/home/jenkins/workspace/vdsm_standard-check-patch/vdsm/lib/yajsonrpc/jsonrpcclient.py", line 78, in callMethod
[check-patch.el7.x86_64] raise exception.JsonRpcNoResponseError(method=methodName)
[check-patch.el7.x86_64] JsonRpcNoResponseError: No response for JSON-RPC request: {'method': 'echo'}
[check-patch.el7.x86_64] -------------------- >> begin captured logging << --------------------
[check-patch.el7.x86_64] 2018-11-30 23:11:39,027 DEBUG (MainThread) [vds.MultiProtocolAcceptor] Creating socket (host='::1', port=0, family=10, socketype=1, proto=6) (protocoldetector:225)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,027 INFO (MainThread) [vds.MultiProtocolAcceptor] Listening at ::1:44347 (protocoldetector:183)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,028 DEBUG (MainThread) [vds.MultiProtocolAcceptor] Adding detector <yajsonrpc.stompserver.StompDetector instance at 0x7fcc061cc4d0> (protocoldetector:210)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,029 DEBUG (MainThread) [Scheduler] Starting scheduler test.Scheduler (schedule:98)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,029 DEBUG (test.Scheduler) [Scheduler] START thread <Thread(test.Scheduler, started daemon 140513327961856)> (func=<bound method Scheduler._run of <vdsm.schedule.Scheduler object at 0x7fcbef8c28d0>>, args=(), kwargs={}) (concurrent:193)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,029 DEBUG (test.Scheduler) [Scheduler] started (schedule:143)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,031 DEBUG (MainThread) [Executor] Starting executor (executor:128)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,032 DEBUG (MainThread) [Executor] Starting worker jsonrpc/0 (executor:286)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,032 DEBUG (jsonrpc/0) [Executor] START thread <Thread(jsonrpc/0, started daemon 140514233075456)> (func=<bound method _Worker._run of <Worker name=jsonrpc/0 waiting task#=0 at 0x7fcbef8cbb90>>, args=(), kwargs={}) (concurrent:193)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,033 DEBUG (jsonrpc/0) [Executor] Worker started (executor:298)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,034 DEBUG (MainThread) [Executor] Starting worker jsonrpc/1 (executor:286)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,037 DEBUG (JsonRpc (StompReactor)) [root] START thread <Thread(JsonRpc (StompReactor), started daemon 140513838692096)> (func=<bound method StompReactor.process_requests of <yajsonrpc.stompserver.StompReactor object at 0x7fcbef7df450>>, args=(), kwargs={}) (concurrent:193)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,037 DEBUG (jsonrpc/1) [Executor] START thread <Thread(jsonrpc/1, started daemon 140513847084800)> (func=<bound method _Worker._run of <Worker name=jsonrpc/1 waiting task#=0 at 0x7fcbef8cb550>>, args=(), kwargs={}) (concurrent:193)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,038 DEBUG (MainThread) [Executor] Starting worker jsonrpc/2 (executor:286)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,039 DEBUG (jsonrpc/1) [Executor] Worker started (executor:298)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,042 DEBUG (jsonrpc/2) [Executor] START thread <Thread(jsonrpc/2, started daemon 140514249860864)> (func=<bound method _Worker._run of <Worker name=jsonrpc/2 waiting task#=0 at 0x7fcbef9f7bd0>>, args=(), kwargs={}) (concurrent:193)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,042 DEBUG (jsonrpc/2) [Executor] Worker started (executor:298)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,044 DEBUG (MainThread) [Executor] Starting worker jsonrpc/3 (executor:286)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,045 DEBUG (MainThread) [Executor] Starting worker jsonrpc/4 (executor:286)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,046 DEBUG (MainThread) [Executor] Starting worker jsonrpc/5 (executor:286)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,046 DEBUG (jsonrpc/4) [Executor] START thread <Thread(jsonrpc/4, started daemon 140513872262912)> (func=<bound method _Worker._run of <Worker name=jsonrpc/4 waiting task#=0 at 0x7fcbef8c8290>>, args=(), kwargs={}) (concurrent:193)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,049 DEBUG (jsonrpc/4) [Executor] Worker started (executor:298)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,045 DEBUG (jsonrpc/3) [Executor] START thread <Thread(jsonrpc/3, started daemon 140514241468160)> (func=<bound method _Worker._run of <Worker name=jsonrpc/3 waiting task#=0 at 0x7fcbef9f7c90>>, args=(), kwargs={}) (concurrent:193)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,050 DEBUG (jsonrpc/3) [Executor] Worker started (executor:298)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,050 DEBUG (MainThread) [Executor] Starting worker jsonrpc/6 (executor:286)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,051 DEBUG (jsonrpc/6) [Executor] START thread <Thread(jsonrpc/6, started daemon 140513855477504)> (func=<bound method _Worker._run of <Worker name=jsonrpc/6 waiting task#=0 at 0x7fcbef8c89d0>>, args=(), kwargs={}) (concurrent:193)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,052 DEBUG (jsonrpc/6) [Executor] Worker started (executor:298)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,058 DEBUG (MainThread) [Executor] Starting worker jsonrpc/7 (executor:286)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,059 DEBUG (jsonrpc/7) [Executor] START thread <Thread(jsonrpc/7, started daemon 140513830299392)> (func=<bound method _Worker._run of <Worker name=jsonrpc/7 waiting task#=0 at 0x7fcbef8c8fd0>>, args=(), kwargs={}) (concurrent:193)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,060 DEBUG (jsonrpc/7) [Executor] Worker started (executor:298)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,059 DEBUG (jsonrpc/5) [Executor] START thread <Thread(jsonrpc/5, started daemon 140513863870208)> (func=<bound method _Worker._run of <Worker name=jsonrpc/5 waiting task#=0 at 0x7fcbef8c8f90>>, args=(), kwargs={}) (concurrent:193)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,062 DEBUG (JsonRpcServer) [root] START thread <Thread(JsonRpcServer, started daemon 140513344747264)> (func=<bound method JsonRpcServer.serve_requests of <yajsonrpc.JsonRpcServer object at 0x7fcbef8c2950>>, args=(), kwargs={}) (concurrent:193)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,065 DEBUG (MainThread) [yajsonrpc.protocols.stomp.AsyncClient] handle connect: outbox=deque([<StompFrame command='CONNECT'>]) (stompclient:117)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,065 DEBUG (MainThread) [yajsonrpc.protocols.stomp.AsyncClient] subscribe: outbox=deque([<StompFrame command='CONNECT'>, <StompFrame command='SUBSCRIBE'>]) (stompclient:208)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,067 DEBUG (jsonrpc/5) [Executor] Worker started (executor:298)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,068 INFO (Detector thread) [ProtocolDetector.AcceptorImpl] Accepted connection from ::1:34462 (protocoldetector:61)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,068 DEBUG (Client ::1:44347) [root] START thread <Thread(Client ::1:44347, started daemon 140513319569152)> (func=<bound method Reactor.process_requests of <yajsonrpc.betterAsyncore.Reactor object at 0x7fcbef86ec90>>, args=(), kwargs={}) (concurrent:193)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,072 DEBUG (Client ::1:44347) [stomp.AsyncDispatcher] handle_write: sending frame: <StompFrame command='CONNECT'> (stomp:497)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,071 DEBUG (MainThread) [jsonrpc.AsyncoreClient] Sending response (stompclient:299)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,073 DEBUG (Client ::1:44347) [stomp.AsyncDispatcher] handle_write: sending 'CONNECT\naccept-version:1.2\nheart-beat:0,24000\n\n\x00' (stomp:500)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,077 DEBUG (Detector thread) [ProtocolDetector.Detector] Using required_size=11 (protocoldetector:89)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,078 DEBUG (Client ::1:44347) [stomp.AsyncDispatcher] handle_write: sending frame: <StompFrame command='SUBSCRIBE'> (stomp:497)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,078 DEBUG (Client ::1:44347) [stomp.AsyncDispatcher] handle_write: sending 'SUBSCRIBE\nack:auto\ndestination:00397ca9-7f39-4602-b115-7ce5bd06a6dd\nid:947a595d-d086-4c48-a0e9-587b42abc6f2\n\n\x00' (stomp:500)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,080 INFO (Detector thread) [ProtocolDetector.Detector] Detected protocol stomp from ::1:34462 (protocoldetector:125)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,081 DEBUG (Detector thread) [stomp.AsyncDispatcher] handle_read: received data: 'CONNECT\naccept-version:1.2\nheart-beat:0,24000\n\n\x00SUBSCRIBE\nack:auto\ndestination:00397ca9-7f39-4602-b115-7ce5bd06a6dd\nid:947a595d-d086-4c48-a0e9-587b42abc6f2\n\n\x00' (stomp:412)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,081 DEBUG (Detector thread) [stomp.AsyncDispatcher] handle_read: handling frame: <StompFrame command=u'CONNECT'> (stomp:418)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,081 INFO (Detector thread) [Broker.StompAdapter] Processing CONNECT request (stompserver:95)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,082 DEBUG (JsonRpc (StompReactor)) [stomp.AsyncDispatcher] handle_write: sending frame: <StompFrame command='CONNECTED'> (stomp:497)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,082 DEBUG (JsonRpc (StompReactor)) [stomp.AsyncDispatcher] handle_write: sending 'CONNECTED\nversion:1.2\nheart-beat:24000,0\n\n\x00' (stomp:500)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,083 DEBUG (Client ::1:44347) [stomp.AsyncDispatcher] handle_read: received data: 'CONNECTED\nversion:1.2\nheart-beat:24000,0\n\n\x00' (stomp:412)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,084 DEBUG (Client ::1:44347) [stomp.AsyncDispatcher] handle_read: handling frame: <StompFrame command=u'CONNECTED'> (stomp:418)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,084 DEBUG (Client ::1:44347) [yajsonrpc.protocols.stomp.AsyncClient] Stomp connection established (stompclient:139)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,086 DEBUG (MainThread) [yajsonrpc.protocols.stomp.AsyncClient] Sending frame: <StompFrame command='SEND'> (stompclient:177)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,086 DEBUG (Detector thread) [stomp.AsyncDispatcher] handle_read: handling frame: <StompFrame command=u'SUBSCRIBE'> (stomp:418)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,087 DEBUG (Client ::1:44347) [stomp.AsyncDispatcher] handle_write: sending frame: <StompFrame command='SEND'> (stomp:497)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,088 DEBUG (Client ::1:44347) [stomp.AsyncDispatcher] handle_write: sending 'SEND\nreply-to:00397ca9-7f39-4602-b115-7ce5bd06a6dd\ndestination:jms.topic.vdsm_requests\ncontent-type:application/json\ncontent-length:200\n\n[{"params": ["Lorem ipsum dolor sit amet, consectetur adipisicing elit, sed do eiusmod tempor incididunt ut labore"], "jsonrpc": "2.0", "method": "echo", "id": "4c11fd4d-de1a-48a3-9288-4d60a9556759"}]\x00' (stomp:500)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,089 DEBUG (JsonRpc (StompReactor)) [stomp.AsyncDispatcher] handle_read: received data: 'SEND\nreply-to:00397ca9-7f39-4602-b115-7ce5bd06a6dd\ndestination:jms.topic.vdsm_requests\ncontent-type:application/json\ncontent-length:200\n\n[{"params": ["Lorem ipsum dolor sit amet, consectetur adipisicing elit, sed do eiusmod tempor incididunt ut labore"], "jsonrpc": "2.0", "method": "echo", "id": "4c11fd4d-de1a-48a3-9288-4d60a9556759"}]\x00' (stomp:412)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,089 DEBUG (JsonRpc (StompReactor)) [stomp.AsyncDispatcher] handle_read: handling frame: <StompFrame command=u'SEND'> (stomp:418)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,091 DEBUG (jsonrpc/0) [jsonrpc.JsonRpcServer] Calling 'echo' in bridge with [u'Lorem ipsum dolor sit amet, consectetur adipisicing elit, sed do eiusmod tempor incididunt ut labore'] (__init__:329)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,091 DEBUG (jsonrpc/0) [jsonrpc.JsonRpcServer] Return 'echo' in bridge with Lorem ipsum dolor sit amet, consectetur adipisicing elit, sed do eiusmod tempor incididunt ut labore (__init__:356)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,092 INFO (jsonrpc/0) [jsonrpc.JsonRpcServer] RPC call echo succeeded in 0.00 seconds (__init__:312)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,087 INFO (Detector thread) [Broker.StompAdapter] Subscribe command received (stompserver:124)
[check-patch.el7.x86_64] 2018-11-30 23:11:39,093 DEBUG (Detector thread) [protocoldetector.StompDetector] Stomp detected from ('::1', 34462) (stompserver:413)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,088 DEBUG (MainThread) [vds.MultiProtocolAcceptor] Stopping Acceptor (protocoldetector:214)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,091 INFO (MainThread) [jsonrpc.JsonRpcServer] Stopping JsonRPC Server (__init__:442)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,092 DEBUG (JsonRpc (StompReactor)) [root] FINISH thread <Thread(JsonRpc (StompReactor), started daemon 140513838692096)> (concurrent:196)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,093 DEBUG (MainThread) [Executor] Stopping executor (executor:137)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,095 DEBUG (jsonrpc/3) [Executor] Worker stopped (executor:303)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,096 DEBUG (jsonrpc/5) [Executor] Worker stopped (executor:303)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,097 DEBUG (jsonrpc/3) [Executor] FINISH thread <Thread(jsonrpc/3, started daemon 140514241468160)> (concurrent:196)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,098 DEBUG (jsonrpc/5) [Executor] FINISH thread <Thread(jsonrpc/5, started daemon 140513863870208)> (concurrent:196)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,099 DEBUG (MainThread) [Executor] Waiting for worker jsonrpc/3 (executor:290)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,100 DEBUG (MainThread) [Executor] Waiting for worker jsonrpc/6 (executor:290)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,101 DEBUG (JsonRpcServer) [root] FINISH thread <Thread(JsonRpcServer, started daemon 140513344747264)> (concurrent:196)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,102 DEBUG (jsonrpc/1) [Executor] Worker stopped (executor:303)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,103 DEBUG (jsonrpc/1) [Executor] FINISH thread <Thread(jsonrpc/1, started daemon 140513847084800)> (concurrent:196)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,104 DEBUG (Client ::1:44347) [root] FINISH thread <Thread(Client ::1:44347, started daemon 140513319569152)> (concurrent:196)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,105 DEBUG (jsonrpc/4) [Executor] Worker stopped (executor:303)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,106 DEBUG (jsonrpc/6) [Executor] Worker stopped (executor:303)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,104 DEBUG (jsonrpc/2) [Executor] Worker stopped (executor:303)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,107 DEBUG (jsonrpc/4) [Executor] FINISH thread <Thread(jsonrpc/4, started daemon 140513872262912)> (concurrent:196)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,107 DEBUG (jsonrpc/0) [Executor] Worker stopped (executor:303)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,108 DEBUG (jsonrpc/6) [Executor] FINISH thread <Thread(jsonrpc/6, started daemon 140513855477504)> (concurrent:196)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,108 DEBUG (jsonrpc/7) [Executor] Worker stopped (executor:303)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,111 DEBUG (jsonrpc/7) [Executor] FINISH thread <Thread(jsonrpc/7, started daemon 140513830299392)> (concurrent:196)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,108 DEBUG (jsonrpc/2) [Executor] FINISH thread <Thread(jsonrpc/2, started daemon 140514249860864)> (concurrent:196)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,112 DEBUG (jsonrpc/0) [Executor] FINISH thread <Thread(jsonrpc/0, started daemon 140514233075456)> (concurrent:196)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,114 DEBUG (MainThreadCoverage.py warning: Module /home/jenkins/workspace/vdsm_standard-check-patch/vdsm/vdsm was never imported. (module-not-imported)
[check-patch.el7.x86_64] ) [Executor] Waiting for worker jsonrpc/7 (executor:290)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,114 DEBUG (MainThread) [Executor] Waiting for worker jsonrpc/4 (executor:290)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,114 DEBUG (MainThread) [Executor] Waiting for worker jsonrpc/5 (executor:290)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,115 DEBUG (MainThread) [Executor] Waiting for worker jsonrpc/0 (executor:290)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,115 DEBUG (MainThread) [Executor] Waiting for worker jsonrpc/2 (executor:290)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,116 DEBUG (MainThread) [Executor] Waiting for worker jsonrpc/1 (executor:290)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,117 DEBUG (MainThread) [Scheduler] Stopping scheduler test.Scheduler (schedule:110)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,117 DEBUG (test.Scheduler) [Scheduler] stopped (schedule:146)
[check-patch.el7.x86_64] 2018-11-30 23:11:54,118 DEBUG (test.Scheduler) [Scheduler] FINISH thread <Thread(test.Scheduler, started daemon 140513327961856)> (concurrent:196)
[check-patch.el7.x86_64] --------------------- >> end captured logging << ---------------------
_______________________________________________
Devel mailing list -- [email protected]
To unsubscribe send an email to [email protected]
Privacy Statement: https://www.ovirt.org/site/privacy-policy/
oVirt Code of Conduct:
https://www.ovirt.org/community/about/community-guidelines/
List Archives:
https://lists.ovirt.org/archives/list/[email protected]/message/JMJPWFP3TO4M66Z2C6IGUTT4QYJCACPV/
