- Devel - oVirt List Archives

[VDSM] Notification in vdsm client
by Piotr Kliczewski 02 Jan '17

02 Jan '17

All, Some time ago during discussion we noticed that we are missing ability to send/receive events from vdsm client [1]. Initially we thought that having [2] would be enough to support notification between engine and vdsm. Now we know we need it for [1]. I would like to collect potential use cases from mom, hosted engine and others so we could design the api to enable them. As part of the work I would like to see whether there is a need to have global event topic or have name convention and use more granular queues. Do we have any use cases to subscribe to additional topic(s) during life time of a client or subscription during instantiation is good enough. Thanks, Piotr [1] https://github.com/oVirt/vdsm/blob/master/lib/vdsmclient/client.py [2] https://github.com/oVirt/vdsm/blob/master/vdsm/clientIF.py#L149

3 2

hotplug_disk test failed
by Gil Shinar 02 Jan '17

02 Jan '17

Hi, The above test failed. Here are the VDSM and engine logs: http://jenkins.ovirt.org/job/test-repo_ovirt_experimental_4.1/88/artifact/e… For the exact same patch, this test has failed for fc24 but succeeded for el7. Thanks Gil

2 2

engine: the link to host-deploy log is wrong
by Yaniv Bronheim 02 Jan '17

02 Jan '17

Hi, I'm not sure if I'm right or wrong so before filing a bug let me know if I don't miss anything - I think the audit log on fail deploy that says the path for the deploy log is wrong. few times I already faced that it points to somewhere under /tmp/ovirt-host-deploy... but the log is actually under /var/log/ovirt-engine/host-deploy/... -- *Yaniv Bronhaim.*

3 4

[VDSM] Tests leaking child processes --with-leaked-processes
by Nir Soffer 30 Dec '16

30 Dec '16

Hi all, The most common test failure on travis (and when running locally) is tests failing with EINTR: IOError: [Errno 4] Interrupted system call This happens because we are using zombiereaper, and it adds a signal handler for SIGCHLD. When a test leaks a child process and the child process terminates, the test runner get a SIGCHLD. If this happens when the test framework is writing to stdout, the write is interrupted and the test fail, failing the entire build. Here is an example failure on travis: https://travis-ci.org/oVirt/vdsm/jobs/187464715 To fix this we need to find the buggy tests (or tested code) leaking child processes. I added a new plugin for this here: https://gerrit.ovirt.org/69324 (mostly stolen from https://gerrit.ovirt.org/69040) Here is the result of running this plugin with current tests: $ make check NOSE_WITH_LEAKED_PROCESSES=1 ... ====================================================================== ERROR: test_running_repr (storage_check_test.TestDirectioChecker) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "3858" } ] -------------------- >> begin captured stdout << --------------------- <DirectioChecker /path running next_check=4321478.96 at 0x7f0f99812e90> --------------------- >> end captured stdout << ---------------------- -------------------- >> begin captured logging << -------------------- 2016-12-30 02:21:32,478 DEBUG (MainThread) [storage.check] Checker '/path' started (check:233) 2016-12-30 02:21:32,479 DEBUG (MainThread) [storage.check] START check '/path' (delay=0.00) (check:283) 2016-12-30 02:21:32,489 DEBUG (MainThread) [storage.asyncevent] Closing <EventLoop running=False closed=False at 0x139704976616848> (asyncevent:215) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: test_running_start_raises (storage_check_test.TestDirectioChecker) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "3861" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:21:32,513 DEBUG (MainThread) [storage.check] Checker '/path' started (check:233) 2016-12-30 02:21:32,514 DEBUG (MainThread) [storage.check] START check '/path' (delay=0.00) (check:283) 2016-12-30 02:21:32,524 DEBUG (MainThread) [storage.asyncevent] Closing <EventLoop running=False closed=False at 0x139704979209232> (asyncevent:215) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: test_stopping_repr (storage_check_test.TestDirectioChecker) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "3864" } ] -------------------- >> begin captured stdout << --------------------- <DirectioChecker /path stopping at 0x7f0f99812cd0> --------------------- >> end captured stdout << ---------------------- -------------------- >> begin captured logging << -------------------- 2016-12-30 02:21:32,548 DEBUG (MainThread) [storage.check] Checker '/path' started (check:233) 2016-12-30 02:21:32,548 DEBUG (MainThread) [storage.check] START check '/path' (delay=0.00) (check:283) 2016-12-30 02:21:32,557 DEBUG (MainThread) [storage.check] Checker '/path' stopping (check:250) 2016-12-30 02:21:32,558 DEBUG (MainThread) [storage.asyncevent] Closing <EventLoop running=False closed=False at 0x139704976616592> (asyncevent:215) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: test_stopping_start_raises (storage_check_test.TestDirectioChecker) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "3867" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:21:32,586 DEBUG (MainThread) [storage.check] Checker '/path' started (check:233) 2016-12-30 02:21:32,586 DEBUG (MainThread) [storage.check] START check '/path' (delay=0.00) (check:283) 2016-12-30 02:21:32,596 DEBUG (MainThread) [storage.check] Checker '/path' stopping (check:250) 2016-12-30 02:21:32,597 DEBUG (MainThread) [storage.asyncevent] Closing <EventLoop running=False closed=False at 0x139704976616720> (asyncevent:215) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: test_stopping_stop_ignored (storage_check_test.TestDirectioChecker) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "3870" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:21:32,621 DEBUG (MainThread) [storage.check] Checker '/path' started (check:233) 2016-12-30 02:21:32,622 DEBUG (MainThread) [storage.check] START check '/path' (delay=0.00) (check:283) 2016-12-30 02:21:32,632 DEBUG (MainThread) [storage.check] Checker '/path' stopping (check:250) 2016-12-30 02:21:32,632 DEBUG (MainThread) [storage.asyncevent] Closing <EventLoop running=False closed=False at 0x139704976616912> (asyncevent:215) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: test_taskset_missing (storage_check_test.TestDirectioChecker) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "3873" } ] -------------------- >> begin captured stdout << --------------------- [<CheckResult path=/var/tmp/tmpaIeNcE rc=127 err='Error starting process: [Errno 2] No such file or directory' time=4321479.14 elapsed=0.01 at 0x7f0f99a8bc90>] --------------------- >> end captured stdout << ---------------------- -------------------- >> begin captured logging << -------------------- 2016-12-30 02:21:32,658 DEBUG (MainThread) [storage.check] Checker '/var/tmp/tmpaIeNcE' started (check:233) 2016-12-30 02:21:32,658 DEBUG (MainThread) [storage.check] START check '/var/tmp/tmpaIeNcE' (delay=0.00) (check:283) 2016-12-30 02:21:32,662 DEBUG (MainThread) [storage.check] FINISH check '/var/tmp/tmpaIeNcE' (rc=127, elapsed=0.01) (check:328) 2016-12-30 02:21:32,663 INFO (MainThread) [storage.asyncevent] Stopping <EventLoop running=False closed=False at 0x139704976616272> (asyncevent:194) 2016-12-30 02:21:32,663 INFO (MainThread) [storage.asyncevent] Starting <EventLoop running=True closed=False at 0x139704976616272> (asyncevent:122) 2016-12-30 02:21:32,663 DEBUG (MainThread) [storage.asyncevent] <EventLoop running=False closed=False at 0x139704976616272> stopped (asyncevent:130) 2016-12-30 02:21:32,664 DEBUG (MainThread) [storage.asyncevent] Closing <EventLoop running=False closed=False at 0x139704976616272> (asyncevent:215) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: testTimeout (storage_iscsi_test.RescanTimeoutTests) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "sleep 2", "pid": "4293" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:21:37,279 DEBUG (MainThread) [storage.SamplingMethod] Trying to enter sampling method (vdsm.storage.iscsi.rescan) (misc:467) 2016-12-30 02:21:37,279 DEBUG (MainThread) [storage.SamplingMethod] Got in to sampling method (misc:470) 2016-12-30 02:21:37,279 DEBUG (MainThread) [storage.ISCSI] Performing SCSI scan, this will take up to 1 seconds (iscsi:457) 2016-12-30 02:21:37,279 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-3 sleep 2 (cwd None) (commands:69) 2016-12-30 02:21:38,285 DEBUG (MainThread) [storage.SamplingMethod] Returning last result (misc:477) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: test (storage_misc_test.AsyncProcTests) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "4367" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:21:39,392 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-3 cat (cwd None) (commands:69) 2016-12-30 02:21:39,402 INFO (MainThread) [AsyncProcTests] Writing data to std out (storage_misc_test:241) 2016-12-30 02:21:39,403 INFO (MainThread) [AsyncProcTests] Written data reading (storage_misc_test:244) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: testCommunicate (storage_misc_test.AsyncProcTests) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "4370" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:21:39,426 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-3 /bin/dd (cwd None) (commands:69) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: testMutiWrite (storage_misc_test.AsyncProcTests) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "4373" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:21:40,463 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-3 cat (cwd None) (commands:69) 2016-12-30 02:21:40,473 INFO (MainThread) [AsyncProcTests] Writing data to std out (storage_misc_test:256) 2016-12-30 02:21:40,473 INFO (MainThread) [AsyncProcTests] Writing more data to std out (storage_misc_test:258) 2016-12-30 02:21:40,473 INFO (MainThread) [AsyncProcTests] Written data reading (storage_misc_test:261) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: testWaitCond (storage_misc_test.AsyncProcTests) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "4376" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:21:40,501 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-3 sleep 12 (cwd None) (commands:69) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: testWaitTimeout (storage_misc_test.AsyncProcTests) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "4379" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:21:42,537 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-3 sleep 12 (cwd None) (commands:69) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: testWriteLargeData (storage_misc_test.AsyncProcTests) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "4382" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:21:44,572 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-3 cat (cwd None) (commands:69) 2016-12-30 02:21:44,580 INFO (MainThread) [AsyncProcTests] Writing data to std out (storage_misc_test:286) 2016-12-30 02:21:44,582 INFO (MainThread) [AsyncProcTests] Written data reading (storage_misc_test:289) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: Test that stop really stops the copying process. ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "4413" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:21:45,963 DEBUG (MainThread) [storage.Misc.excCmd] /usr/bin/taskset --cpu-list 0-3 /usr/bin/nice -n 19 /usr/bin/ionice -c 3 /usr/bin/dd if=/tmp/tmpUsJOxV of=/tmp/tmpjQOhqP bs=64 seek=0 skip=0 conv=notrunc,fdatasync count=1 (cwd None) (commands:69) 2016-12-30 02:21:45,974 INFO (MainThread) [DdWatchCopy] Looks like it stopped! (storage_misc_test:465) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: testNoCommandWithoutAffinity (storage_misc_test.ExecCmd) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "4449" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:22:02,309 DEBUG (MainThread) [root] I.DONT.EXIST (cwd None) (commands:69) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: Test that stopping the process really works. ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "4582" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:22:06,000 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-3 sleep 10 (cwd None) (commands:69) 2016-12-30 02:22:06,005 INFO (MainThread) [WatchCmd] Looks like task stopped! (storage_misc_test:897) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: testAmountOfInstancesPerPoolName (storage_outofprocess_test.OopWrapperTests) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "/usr/libexec/ioprocess --read-pipe-fd 93 --write-pipe-fd 92 --max-threads 10 --max-queued-requests 10", "pid": "4861" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:22:18,447 DEBUG (MainThread) [storage.oop] Creating ioprocess Global (outOfProcess:87) 2016-12-30 02:22:18,447 INFO (MainThread) [IOProcessClient] Starting client ioprocess-14 (__init__:325) 2016-12-30 02:22:18,447 DEBUG (MainThread) [IOProcessClient] Starting ioprocess for client ioprocess-14 (__init__:334) 2016-12-30 02:22:18,452 DEBUG (MainThread) [IOProcessClient] Starting communication thread for client ioprocess-14 (__init__:386) 2016-12-30 02:22:18,452 DEBUG (MainThread) [IOProcessClient] Communication thread for client ioprocess-14 started (__init__:398) 2016-12-30 02:22:18,452 DEBUG (MainThread) [storage.oop] Creating ioprocess A (outOfProcess:87) 2016-12-30 02:22:18,452 INFO (MainThread) [IOProcessClient] Starting client ioprocess-15 (__init__:325) 2016-12-30 02:22:18,453 DEBUG (MainThread) [IOProcessClient] Starting ioprocess for client ioprocess-15 (__init__:334) 2016-12-30 02:22:18,453 INFO (ioprocess communication (4848)) [IOProcess] Starting ioprocess (__init__:447) 2016-12-30 02:22:18,453 DEBUG (ioprocess communication (4848)) [IOProcess] Closing unrelated FDs... (__init__:445) 2016-12-30 02:22:18,453 DEBUG (ioprocess communication (4848)) [IOProcess] Opening communication channels... (__init__:445) 2016-12-30 02:22:18,457 DEBUG (MainThread) [IOProcessClient] Starting communication thread for client ioprocess-15 (__init__:386) 2016-12-30 02:22:18,458 DEBUG (MainThread) [IOProcessClient] Communication thread for client ioprocess-15 started (__init__:398) 2016-12-30 02:22:18,458 INFO (ioprocess communication (4854)) [IOProcess] Starting ioprocess (__init__:447) 2016-12-30 02:22:18,458 DEBUG (ioprocess communication (4854)) [IOProcess] Closing unrelated FDs... (__init__:445) 2016-12-30 02:22:18,458 DEBUG (ioprocess communication (4854)) [IOProcess] Opening communication channels... (__init__:445) 2016-12-30 02:22:24,464 DEBUG (MainThread) [storage.oop] Removing idle ioprocess A (outOfProcess:77) 2016-12-30 02:22:24,464 INFO (MainThread) [IOProcessClient] Closing client ioprocess-15 (__init__:593) 2016-12-30 02:22:24,464 DEBUG (MainThread) [storage.oop] Creating ioprocess B (outOfProcess:87) 2016-12-30 02:22:24,465 INFO (MainThread) [IOProcessClient] Starting client ioprocess-16 (__init__:325) 2016-12-30 02:22:24,465 DEBUG (MainThread) [IOProcessClient] Starting ioprocess for client ioprocess-16 (__init__:334) 2016-12-30 02:22:24,470 DEBUG (MainThread) [IOProcessClient] Starting communication thread for client ioprocess-16 (__init__:386) 2016-12-30 02:22:24,470 DEBUG (MainThread) [IOProcessClient] Communication thread for client ioprocess-16 started (__init__:398) 2016-12-30 02:22:24,515 INFO (ioprocess communication (4861)) [IOProcess] Starting ioprocess (__init__:447) 2016-12-30 02:22:24,515 DEBUG (ioprocess communication (4861)) [IOProcess] Closing unrelated FDs... (__init__:445) 2016-12-30 02:22:24,516 DEBUG (ioprocess communication (4861)) [IOProcess] Opening communication channels... (__init__:445) 2016-12-30 02:22:25,557 INFO (MainThread) [IOProcessClient] Closing client ioprocess-14 (__init__:593) 2016-12-30 02:22:25,557 DEBUG (MainThread) [IOProcessClient] Waiting for communication thread for ioprocess-14 (__init__:599) 2016-12-30 02:22:25,557 INFO (ioprocess communication (4848)) [IOProcessClient] shutdown requested (__init__:124) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: testDifferentPoolName (storage_outofprocess_test.OopWrapperTests) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "/usr/libexec/ioprocess --read-pipe-fd 109 --write-pipe-fd 108 --max-threads 10 --max-queued-requests 10", "pid": "4882" }, { "command": "/usr/libexec/ioprocess --read-pipe-fd 101 --write-pipe-fd 99 --max-threads 10 --max-queued-requests 10", "pid": "4876" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:22:25,583 DEBUG (MainThread) [storage.oop] Creating ioprocess Global (outOfProcess:87) 2016-12-30 02:22:25,584 INFO (MainThread) [IOProcessClient] Starting client ioprocess-17 (__init__:325) 2016-12-30 02:22:25,584 DEBUG (MainThread) [IOProcessClient] Starting ioprocess for client ioprocess-17 (__init__:334) 2016-12-30 02:22:25,592 DEBUG (MainThread) [IOProcessClient] Starting communication thread for client ioprocess-17 (__init__:386) 2016-12-30 02:22:25,593 DEBUG (MainThread) [IOProcessClient] Communication thread for client ioprocess-17 started (__init__:398) 2016-12-30 02:22:25,593 DEBUG (MainThread) [storage.oop] Creating ioprocess A (outOfProcess:87) 2016-12-30 02:22:25,593 INFO (ioprocess communication (4870)) [IOProcess] Starting ioprocess (__init__:447) 2016-12-30 02:22:25,593 DEBUG (ioprocess communication (4870)) [IOProcess] Closing unrelated FDs... (__init__:445) 2016-12-30 02:22:25,594 INFO (MainThread) [IOProcessClient] Starting client ioprocess-18 (__init__:325) 2016-12-30 02:22:25,594 DEBUG (MainThread) [IOProcessClient] Starting ioprocess for client ioprocess-18 (__init__:334) 2016-12-30 02:22:25,594 DEBUG (ioprocess communication (4870)) [IOProcess] Opening communication channels... (__init__:445) 2016-12-30 02:22:25,604 DEBUG (MainThread) [IOProcessClient] Starting communication thread for client ioprocess-18 (__init__:386) 2016-12-30 02:22:25,604 DEBUG (MainThread) [IOProcessClient] Communication thread for client ioprocess-18 started (__init__:398) 2016-12-30 02:22:25,605 DEBUG (MainThread) [storage.oop] Creating ioprocess B (outOfProcess:87) 2016-12-30 02:22:25,605 INFO (ioprocess communication (4876)) [IOProcess] Starting ioprocess (__init__:447) 2016-12-30 02:22:25,605 DEBUG (ioprocess communication (4876)) [IOProcess] Closing unrelated FDs... (__init__:445) 2016-12-30 02:22:25,605 INFO (MainThread) [IOProcessClient] Starting client ioprocess-19 (__init__:325) 2016-12-30 02:22:25,605 DEBUG (MainThread) [IOProcessClient] Starting ioprocess for client ioprocess-19 (__init__:334) 2016-12-30 02:22:25,605 DEBUG (ioprocess communication (4876)) [IOProcess] Opening communication channels... (__init__:445) 2016-12-30 02:22:25,610 DEBUG (MainThread) [IOProcessClient] Starting communication thread for client ioprocess-19 (__init__:386) 2016-12-30 02:22:25,610 DEBUG (MainThread) [IOProcessClient] Communication thread for client ioprocess-19 started (__init__:398) 2016-12-30 02:22:25,611 INFO (MainThread) [IOProcessClient] Closing client ioprocess-16 (__init__:593) 2016-12-30 02:22:25,611 INFO (MainThread) [IOProcessClient] Closing client ioprocess-17 (__init__:593) 2016-12-30 02:22:25,611 INFO (ioprocess communication (4882)) [IOProcess] Starting ioprocess (__init__:447) 2016-12-30 02:22:25,611 DEBUG (ioprocess communication (4882)) [IOProcess] Closing unrelated FDs... (__init__:445) 2016-12-30 02:22:25,611 INFO (ioprocess communication (4870)) [IOProcessClient] shutdown requested (__init__:124) 2016-12-30 02:22:25,612 DEBUG (MainThread) [IOProcessClient] Waiting for communication thread for ioprocess-17 (__init__:599) 2016-12-30 02:22:25,612 DEBUG (ioprocess communication (4882)) [IOProcess] Opening communication channels... (__init__:445) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: testSamePoolName (storage_outofprocess_test.OopWrapperTests) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "/usr/libexec/ioprocess --read-pipe-fd 96 --write-pipe-fd 94 --max-threads 10 --max-queued-requests 10", "pid": "4918" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:22:25,718 DEBUG (MainThread) [storage.oop] Creating ioprocess Global (outOfProcess:87) 2016-12-30 02:22:25,719 INFO (MainThread) [IOProcessClient] Starting client ioprocess-22 (__init__:325) 2016-12-30 02:22:25,719 DEBUG (MainThread) [IOProcessClient] Starting ioprocess for client ioprocess-22 (__init__:334) 2016-12-30 02:22:25,723 DEBUG (MainThread) [IOProcessClient] Starting communication thread for client ioprocess-22 (__init__:386) 2016-12-30 02:22:25,724 DEBUG (MainThread) [IOProcessClient] Communication thread for client ioprocess-22 started (__init__:398) 2016-12-30 02:22:25,724 DEBUG (MainThread) [storage.oop] Creating ioprocess A (outOfProcess:87) 2016-12-30 02:22:25,724 INFO (MainThread) [IOProcessClient] Starting client ioprocess-23 (__init__:325) 2016-12-30 02:22:25,724 DEBUG (MainThread) [IOProcessClient] Starting ioprocess for client ioprocess-23 (__init__:334) 2016-12-30 02:22:25,724 INFO (ioprocess communication (4912)) [IOProcess] Starting ioprocess (__init__:447) 2016-12-30 02:22:25,724 DEBUG (ioprocess communication (4912)) [IOProcess] Closing unrelated FDs... (__init__:445) 2016-12-30 02:22:25,725 DEBUG (ioprocess communication (4912)) [IOProcess] Opening communication channels... (__init__:445) 2016-12-30 02:22:25,729 DEBUG (MainThread) [IOProcessClient] Starting communication thread for client ioprocess-23 (__init__:386) 2016-12-30 02:22:25,730 DEBUG (MainThread) [IOProcessClient] Communication thread for client ioprocess-23 started (__init__:398) 2016-12-30 02:22:25,730 INFO (MainThread) [IOProcessClient] Closing client ioprocess-18 (__init__:593) 2016-12-30 02:22:25,730 INFO (ioprocess communication (4918)) [IOProcess] Starting ioprocess (__init__:447) 2016-12-30 02:22:25,730 DEBUG (ioprocess communication (4918)) [IOProcess] Closing unrelated FDs... (__init__:445) 2016-12-30 02:22:25,730 DEBUG (ioprocess communication (4918)) [IOProcess] Opening communication channels... (__init__:445) 2016-12-30 02:22:25,731 INFO (MainThread) [IOProcessClient] Closing client ioprocess-22 (__init__:593) 2016-12-30 02:22:25,731 INFO (ioprocess communication (4912)) [IOProcessClient] shutdown requested (__init__:124) 2016-12-30 02:22:25,731 DEBUG (MainThread) [IOProcessClient] Waiting for communication thread for ioprocess-22 (__init__:599) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: test_get (tasksetTests.AffinityTests) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "7676" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:22:54,549 DEBUG (MainThread) [root] /usr/bin/taskset --pid 7676 (cwd None) (commands:69) 2016-12-30 02:22:54,555 DEBUG (MainThread) [root] SUCCESS: <err> = ''; <rc> = 0 (commands:93) 2016-12-30 02:22:54,555 DEBUG (MainThread) [root] /usr/bin/taskset --pid 567 (cwd None) (commands:69) 2016-12-30 02:22:54,562 DEBUG (MainThread) [root] SUCCESS: <err> = ''; <rc> = 0 (commands:93) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: test_set_from_child(frozenset([0, 3])) (tasksetTests.AffinityTests) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "7684" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:22:54,652 DEBUG (MainThread) [root] /usr/bin/taskset --pid 7684 (cwd None) (commands:69) 2016-12-30 02:22:54,658 DEBUG (MainThread) [root] SUCCESS: <err> = ''; <rc> = 0 (commands:93) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: test_set_from_child(frozenset([0])) (tasksetTests.AffinityTests) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "7689" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:22:54,701 DEBUG (MainThread) [root] /usr/bin/taskset --pid 7689 (cwd None) (commands:69) 2016-12-30 02:22:54,707 DEBUG (MainThread) [root] SUCCESS: <err> = ''; <rc> = 0 (commands:93) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: test_set_from_child(frozenset([1, 2])) (tasksetTests.AffinityTests) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "7694" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:22:54,752 DEBUG (MainThread) [root] /usr/bin/taskset --pid 7694 (cwd None) (commands:69) 2016-12-30 02:22:54,763 DEBUG (MainThread) [root] SUCCESS: <err> = ''; <rc> = 0 (commands:93) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: test_set_from_parent(frozenset([0, 3])) (tasksetTests.AffinityTests) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "7699" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:22:54,797 DEBUG (MainThread) [root] /usr/bin/taskset --pid --cpu-list 0,3 7699 (cwd None) (commands:69) 2016-12-30 02:22:54,808 DEBUG (MainThread) [root] SUCCESS: <err> = ''; <rc> = 0 (commands:93) 2016-12-30 02:22:54,808 DEBUG (MainThread) [root] /usr/bin/taskset --pid 7699 (cwd None) (commands:69) 2016-12-30 02:22:54,813 DEBUG (MainThread) [root] SUCCESS: <err> = ''; <rc> = 0 (commands:93) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: test_set_from_parent(frozenset([0])) (tasksetTests.AffinityTests) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "7704" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:22:54,849 DEBUG (MainThread) [root] /usr/bin/taskset --pid --cpu-list 0 7704 (cwd None) (commands:69) 2016-12-30 02:22:54,855 DEBUG (MainThread) [root] SUCCESS: <err> = ''; <rc> = 0 (commands:93) 2016-12-30 02:22:54,855 DEBUG (MainThread) [root] /usr/bin/taskset --pid 7704 (cwd None) (commands:69) 2016-12-30 02:22:54,861 DEBUG (MainThread) [root] SUCCESS: <err> = ''; <rc> = 0 (commands:93) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: test_set_from_parent(frozenset([1, 2])) (tasksetTests.AffinityTests) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "7710" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:22:54,909 DEBUG (MainThread) [root] /usr/bin/taskset --pid --cpu-list 1,2 7710 (cwd None) (commands:69) 2016-12-30 02:22:54,920 DEBUG (MainThread) [root] SUCCESS: <err> = ''; <rc> = 0 (commands:93) 2016-12-30 02:22:54,920 DEBUG (MainThread) [root] /usr/bin/taskset --pid 7710 (cwd None) (commands:69) 2016-12-30 02:22:54,925 DEBUG (MainThread) [root] SUCCESS: <err> = ''; <rc> = 0 (commands:93) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: testWait(['sleep', '1'], ['sleep', '3'], False) (v2vTests.PipelineProcTests) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "9495" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:23:34,072 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-3 sleep 1 (cwd None) (v2v:1301) 2016-12-30 02:23:34,082 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-3 sleep 3 (cwd None) (v2v:1301) 2016-12-30 02:23:37,086 DEBUG (MainThread) [root] Killing pid=9494 (v2v:679) 2016-12-30 02:23:37,086 DEBUG (MainThread) [root] Killing pid=9495 (v2v:679) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: testWait(['sleep', '3'], ['sleep', '1'], False) (v2vTests.PipelineProcTests) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "9498" }, { "command": "", "pid": "9499" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:23:37,112 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-3 sleep 3 (cwd None) (v2v:1301) 2016-12-30 02:23:37,122 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-3 sleep 1 (cwd None) (v2v:1301) 2016-12-30 02:23:39,134 DEBUG (MainThread) [root] Killing pid=9498 (v2v:679) 2016-12-30 02:23:39,135 DEBUG (MainThread) [root] Killing pid=9499 (v2v:679) --------------------- >> end captured logging << --------------------- ====================================================================== ERROR: testWait(['sleep', '3'], ['sleep', '3'], False) (v2vTests.PipelineProcTests) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/nose/case.py", line 133, in run self.runTest(result) File "/usr/lib/python2.7/site-packages/nose/case.py", line 151, in runTest test(result) AssertionError: Test leaked child processes: [ { "command": "", "pid": "9503" }, { "command": "", "pid": "9504" } ] -------------------- >> begin captured logging << -------------------- 2016-12-30 02:23:39,164 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-3 sleep 3 (cwd None) (v2v:1301) 2016-12-30 02:23:39,176 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-3 sleep 3 (cwd None) (v2v:1301) 2016-12-30 02:23:41,186 DEBUG (MainThread) [root] Killing pid=9503 (v2v:679) 2016-12-30 02:23:41,187 DEBUG (MainThread) [root] Killing pid=9504 (v2v:679) --------------------- >> end captured logging << ---------------------

1 0

Jenkins jobs failure
by Gil Shinar 29 Dec '16

29 Dec '16

Hi all, We have have a merged a patch yesterday that made a very important enhancement to the logs collection of the STD-CI jobs. This merge caused a small regression that we have already found and working on fixing it. Please be patient till this fix will be merged. Thanks Gil

1 1

Jenkins restart
by Gil Shinar 28 Dec '16

28 Dec '16

Hi all, Jenkins restart is planned today at 18:00. Patches that will be sent or merged up to an hour before that time might fail and would need to be re-triggered. If there's any urgent patch that needs to be sent or merged at that time, please let me know before 18:00. Thanks Gil

1 1

Re: [ovirt-devel] ost host addition failure
by Eyal Edri 27 Dec '16

27 Dec '16

Any updates? The tests are still failing on vdsmd won't start from Sunday... master repos havn't been refreshed for a few days due to this. from host deploy log: [1] basic-suite-master-engine/_var_log_ovirt-engine/host-deploy/ovirt-host-deploy-20161227012930-192.168.201.4-14af2bf0.log the job links [2] [1] http://jenkins.ovirt.org/job/test-repo_ovirt_experimental_master/lastComple… 016-12-27 01:29:29 DEBUG otopi.plugins.otopi.services.systemd plugin.execute:921 execute-output: ('/bin/systemctl', 'start', 'vdsmd.service') stdout: 2016-12-27 01:29:29 DEBUG otopi.plugins.otopi.services.systemd plugin.execute:926 execute-output: ('/bin/systemctl', 'start', 'vdsmd.service') stderr: A dependency job for vdsmd.service failed. See 'journalctl -xe' for details. 2016-12-27 01:29:29 DEBUG otopi.context context._executeMethod:142 method exception Traceback (most recent call last): File "/tmp/ovirt-QZ1ucxWFfm/pythonlib/otopi/context.py", line 132, in _executeMethod method['method']() File "/tmp/ovirt-QZ1ucxWFfm/otopi-plugins/ovirt-host-deploy/vdsm/packages.py", line 209, in _start self.services.state('vdsmd', True) File "/tmp/ovirt-QZ1ucxWFfm/otopi-plugins/otopi/services/systemd.py", line 141, in state service=name, RuntimeError: Failed to start service 'vdsmd' 2016-12-27 01:29:29 ERROR otopi.context context._executeMethod:151 Failed to execute stage 'Closing up': Failed to start service 'vdsmd' 2016-12-27 01:29:29 DEBUG otopi.context context.dumpEnvironment:760 ENVIRONMENT DUMP - BEGIN 2016-12-27 01:29:29 DEBUG otopi.context context.dumpEnvironment:770 ENV BASE/error=bool:'True' 2016-12-27 01:29:29 DEBUG otopi.context context.dumpEnvironment:770 ENV BASE/excep [2] http://jenkins.ovirt.org/job/test-repo_ovirt_experimental_master/lastComple… On Sun, Dec 25, 2016 at 11:31 AM, Eyal Edri <eedri(a)redhat.com> wrote: > We should see it fixed here hopefully [1] > > > [1] http://jenkins.ovirt.org/view/All%20Running%20jobs/job/ > test-repo_ovirt_experimental_master/4412/console > > On Sun, Dec 25, 2016 at 11:19 AM, Dan Kenigsberg <danken(a)redhat.com> > wrote: > >> On Sun, Dec 25, 2016 at 10:28 AM, Yaniv Kaul <ykaul(a)redhat.com> wrote: >> > >> > >> > On Sun, Dec 25, 2016 at 9:47 AM, Dan Kenigsberg <danken(a)redhat.com> >> wrote: >> >> >> >> Correct. https://gerrit.ovirt.org/#/c/69052/ >> >> >> >> Can you try adding >> >> lago shell "$vm_name" -c "mkdir -p /var/log/ovirt-imageio-daemon/ && >> >> chown vdsm:kvm /var/log/ovirt-imageio-daemon/" >> > >> > >> > How will it know what is the vdsm user before installing vdsm? >> >> You're right. a hack would have to `chmod a+rwx >> /var/log/ovirt-imageio-daemon/` instead. >> >> > Why not either: >> > 1. Fix it >> >> yes, that's why we've opened >> https://bugzilla.redhat.com/show_bug.cgi?id=1400003 ; now a fix is >> getting merged. I don't know when it is going to be ready in lago's >> repos. >> >> > -or- >> > 2. Revert the offending patch? >> >> I'm not aware of such patch. It's a race that has been there since >> ever, and I don't know why it suddenly pops up so often. >> > > > > -- > Eyal Edri > Associate Manager > RHV DevOps > EMEA ENG Virtualization R&D > Red Hat Israel > > phone: +972-9-7692018 <+972%209-769-2018> > irc: eedri (on #tlv #rhev-dev #rhev-integ) > -- Eyal Edri Associate Manager RHV DevOps EMEA ENG Virtualization R&D Red Hat Israel phone: +972-9-7692018 irc: eedri (on #tlv #rhev-dev #rhev-integ)

4 5

[VDSM] storage_iscsi_test.RescanTimeoutTests test failing
by Edward Haas 26 Dec '16

26 Dec '16

I got this test failing on one of the builds: ( http://jenkins.ovirt.org/job/vdsm_master_check-patch-el7-x86_64/5266/console ) *09:39:16* ======================================================================*09:39:16* FAIL: testTimeout (storage_iscsi_test.RescanTimeoutTests)*09:39:16* ----------------------------------------------------------------------*09:39:16* Traceback (most recent call last):*09:39:16* File "/home/jenkins/workspace/vdsm_master_check-patch-el7-x86_64/vdsm/tests/monkeypatch.py", line 133, in wrapper*09:39:16* return f(*args, **kw)*09:39:16* File "/home/jenkins/workspace/vdsm_master_check-patch-el7-x86_64/vdsm/tests/monkeypatch.py", line 133, in wrapper*09:39:16* return f(*args, **kw)*09:39:16* File "/home/jenkins/workspace/vdsm_master_check-patch-el7-x86_64/vdsm/tests/storage_iscsi_test.py", line 45, in testTimeout*09:39:16* iscsi.rescan()*09:39:16* File "/usr/lib64/python2.7/contextlib.py", line 24, in __exit__*09:39:16* self.gen.next()*09:39:16* File "/home/jenkins/workspace/vdsm_master_check-patch-el7-x86_64/vdsm/tests/storage_iscsi_test.py", line 33, in assertMaxDuration*09:39:16* (elapsed, maxtime))*09:39:16* AssertionError: Operation was too slow 1.32s > 1.20s*09:39:16* -------------------- >> begin captured logging << --------------------*09:39:16* 2016-12-26 09:36:46,857 DEBUG (MainThread) [storage.SamplingMethod] Trying to enter sampling method (vdsm.storage.iscsi.rescan) (misc:467)*09:39:16* 2016-12-26 09:36:46,857 DEBUG (MainThread) [storage.SamplingMethod] Got in to sampling method (misc:470)*09:39:16* 2016-12-26 09:36:46,857 DEBUG (MainThread) [storage.ISCSI] Performing SCSI scan, this will take up to 1 seconds (iscsi:457)*09:39:16* 2016-12-26 09:36:46,858 DEBUG (MainThread) [root] /usr/bin/taskset --cpu-list 0-3 sleep 2 (cwd None) (commands:69)*09:39:16* 2016-12-26 09:36:48,183 DEBUG (MainThread) [storage.SamplingMethod] Returning last result (misc:477)*09:39:16* --------------------- >> end captured logging << --------------------- I was surprised that it uses a time measurement to determine success. Edy.

1 0

Check-merged is broken since we added network test to it
by Yaniv Bronheim 26 Dec '16

26 Dec '16

Hi guys and Leon, https://gerrit.ovirt.org/#/c/68078/ broke the check-merged job with really tough exception: *15:23:34* sh: [17766: 1 (255)] tcsetattr: Inappropriate ioctl for device*15:23:34* Took 2586 seconds*15:23:34* Slave went offline during the build <http://jenkins.ovirt.org/computer/vm0136.workers-phx.ovirt.org/log>*15:23:34* ERROR: Connection was broken: java.io.IOException: Unexpected termination of the channel*15:23:34* at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:50)*15:23:34* Caused by: java.io.EOFException*15:23:34* at java.io.ObjectInputStream$PeekInputStream.readFully(ObjectInputStream.java:2353)*15:23:34* at java.io.ObjectInputStream$BlockDataInputStream.readShort(ObjectInputStream.java:2822)*15:23:34* at java.io.ObjectInputStream.readStreamHeader(ObjectInputStream.java:804)*15:23:34* at java.io.ObjectInputStream.<init>(ObjectInputStream.java:301)*15:23:34* at hudson.remoting.ObjectInputStreamEx.<init>(ObjectInputStreamEx.java:48)*15:23:34* at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:34)*15:23:34* at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:48)*15:23:34* *15:23:34* Build step 'Execute shell' marked build as failure*15:23:34* Performing Post build task... I have no clue what causes it.. we need to investigate in the tests code. you can see it in http://jenkins.ovirt.org/job/vdsm_master_check-merged-el7-x86_64/772/consol… and this for a job run just before it got in, which worked well - http://jenkins.ovirt.org/job/vdsm_master_check-merged-el7-x86_64/688/console I suggest to revert this patch (and backport the revert to ovirt-4.1 branch as well) until figuring what causes it -- *Yaniv Bronhaim.*

4 9

oVirt system tests currently failing to AddHost on master
by Barak Korren 25 Dec '16

25 Dec '16

It hard to tell currently when did this start b/c we had so package issues that made the tests fail before reaching that point most of the day. Since we currently have an issue in Lago with collecting AddHost logs (Hopefully we'll resolve this in the next release early next week), I`ve ran the tests locally and attached the bundle of generated logs to this message. Included in the attached file are engine logs, host-deploy logs and VDSM logs for both test hosts. >From a quick look inside it seems the issue is with VDSM failing to start. Thanks, -- Barak Korren bkorren(a)redhat.com RHCE, RHCi, RHV-DevOps Team https://ifireball.wordpress.com/

5 15