[VDSM] Tests leaking child processes --with-leaked-processes
by Nir Soffer
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 << ---------------------
7 years, 11 months
Jenkins jobs failure
by Gil Shinar
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
7 years, 11 months
Jenkins restart
by Gil Shinar
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
7 years, 11 months
Re: [ovirt-devel] ost host addition failure
by Eyal Edri
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/lastComp...
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/lastComp...
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)
7 years, 12 months
[VDSM] storage_iscsi_test.RescanTimeoutTests test failing
by Edward Haas
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.
7 years, 12 months
Check-merged is broken since we added network test to it
by Yaniv Bronheim
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/cons...
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.*
7 years, 12 months
oVirt system tests currently failing to AddHost on master
by Barak Korren
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/
7 years, 12 months
ovirt.org is back online
by Eyal Edri
The site is back online thanks for Duck in helping clearing the log files
which caused the gear to get stuck.
I understood that the site is planned to move to another location, with
more storage so hopefully these kind of outage will be rare soon after.
--
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)
7 years, 12 months
[Attention] Gerrit 'git://' protocol error
by Nadav Goldin
Hi,
Currently git-daemon is not working on gerrit.ovirt.org, so all
actions with remote configured with 'git://' prefix would
fail(including Jenkins jobs). We are working on resolving the issue,
until then you can use 'https://' for anonymous clones, or
SSH(ssh://username@gerrit.ovirt.org:29418/repo.git).
Thanks,
Nadav.
7 years, 12 months
[VDSM] Support for external leases - possible breakage with development version
by Nir Soffer
Hi all,
I merged today the last patches for supporting external leases.
In storage domain version 4 (the default in ovirt 4.1), there is now
a new volume named "xleases".
When upgrading older storage domain (version 3), we create and
format the new volume.
If you used a development version with storage domain version 4,
your storage domain may not work with current master. You should
recreated such storage domain.
As a workaround, you can create the special volume manually:
File storage:
sudo -u vdsm truncate -s 1G
/rhev/data-center/mnt/server:_path/domain_uuid/dom_md/xleases
Block storage:
lvcreate --name xleases --size 1g domain_uuid
Note that the volume should be also be formatted to actually use
external leases,
but having it should be good enough to keep the system happy.
Thanks,
Nir
7 years, 12 months
