MainThread::INFO::2013-03-20 08:30:04,298::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:30:16,042::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:30:16,178::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:30:16,178::vdsm::98::vds::(run) <_MainThread(MainThread, started 140111195969280)> MainThread::INFO::2013-03-20 08:30:16,178::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:30:16,253::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:30:26,577::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:30:26,580::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:30:26,580::vdsm::98::vds::(run) <_MainThread(MainThread, started 139950224287488)> MainThread::INFO::2013-03-20 08:30:26,580::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:30:26,641::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:30:36,990::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: internal error client socket is closed MainThread::INFO::2013-03-20 08:30:36,993::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:30:36,993::vdsm::98::vds::(run) <_MainThread(MainThread, started 140074462701312)> MainThread::INFO::2013-03-20 08:30:36,993::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:30:37,055::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:30:47,416::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: internal error client socket is closed MainThread::INFO::2013-03-20 08:30:47,418::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:30:47,418::vdsm::98::vds::(run) <_MainThread(MainThread, started 140545647191808)> MainThread::INFO::2013-03-20 08:30:47,418::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:30:47,479::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:30:57,835::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:30:57,837::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:30:57,837::vdsm::98::vds::(run) <_MainThread(MainThread, started 140016974911232)> MainThread::INFO::2013-03-20 08:30:57,837::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:30:57,899::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:31:08,267::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:31:08,270::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:31:08,270::vdsm::98::vds::(run) <_MainThread(MainThread, started 139891964954368)> MainThread::INFO::2013-03-20 08:31:08,270::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:31:08,331::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:31:18,688::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: internal error client socket is closed MainThread::INFO::2013-03-20 08:31:18,691::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:31:18,691::vdsm::98::vds::(run) <_MainThread(MainThread, started 140414776178432)> MainThread::INFO::2013-03-20 08:31:18,691::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:31:18,752::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:31:29,108::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:31:29,110::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:31:29,110::vdsm::98::vds::(run) <_MainThread(MainThread, started 140302042396416)> MainThread::INFO::2013-03-20 08:31:29,111::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:31:29,174::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:31:39,528::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:31:39,531::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:31:39,531::vdsm::98::vds::(run) <_MainThread(MainThread, started 139713600907008)> MainThread::INFO::2013-03-20 08:31:39,531::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:31:39,592::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:31:49,945::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:31:49,947::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:31:49,947::vdsm::98::vds::(run) <_MainThread(MainThread, started 140411697813248)> MainThread::INFO::2013-03-20 08:31:49,947::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:31:50,009::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:32:00,362::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: internal error client socket is closed MainThread::INFO::2013-03-20 08:32:00,364::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:32:00,364::vdsm::98::vds::(run) <_MainThread(MainThread, started 140518521210624)> MainThread::INFO::2013-03-20 08:32:00,364::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:32:00,426::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:32:10,782::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:32:10,784::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:32:10,785::vdsm::98::vds::(run) <_MainThread(MainThread, started 140595871168256)> MainThread::INFO::2013-03-20 08:32:10,785::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:32:10,847::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:32:21,054::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:32:21,061::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:32:21,062::vdsm::98::vds::(run) <_MainThread(MainThread, started 140173848827648)> MainThread::INFO::2013-03-20 08:32:21,062::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:32:21,136::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:32:31,514::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:32:31,517::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:32:31,517::vdsm::98::vds::(run) <_MainThread(MainThread, started 140205153306368)> MainThread::INFO::2013-03-20 08:32:31,517::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:32:31,578::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:32:41,940::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:32:41,942::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:32:41,942::vdsm::98::vds::(run) <_MainThread(MainThread, started 140460879476480)> MainThread::INFO::2013-03-20 08:32:41,942::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:32:42,003::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:32:52,363::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:32:52,365::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:32:52,365::vdsm::98::vds::(run) <_MainThread(MainThread, started 140425220568832)> MainThread::INFO::2013-03-20 08:32:52,365::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:32:52,427::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:33:02,781::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:33:02,784::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:33:02,784::vdsm::98::vds::(run) <_MainThread(MainThread, started 140039400609536)> MainThread::INFO::2013-03-20 08:33:02,784::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:33:02,847::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:33:13,211::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:33:13,213::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:33:13,213::vdsm::98::vds::(run) <_MainThread(MainThread, started 140272980981504)> MainThread::INFO::2013-03-20 08:33:13,213::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:33:13,275::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:33:23,635::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:33:23,637::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:33:23,637::vdsm::98::vds::(run) <_MainThread(MainThread, started 140384977188608)> MainThread::INFO::2013-03-20 08:33:23,637::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:33:23,698::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:33:34,054::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:33:34,056::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:33:34,056::vdsm::98::vds::(run) <_MainThread(MainThread, started 140657955694336)> MainThread::INFO::2013-03-20 08:33:34,057::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:33:34,118::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:33:44,473::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:33:44,476::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:33:44,476::vdsm::98::vds::(run) <_MainThread(MainThread, started 139776386000640)> MainThread::INFO::2013-03-20 08:33:44,476::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:33:44,537::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:33:54,893::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: internal error client socket is closed MainThread::INFO::2013-03-20 08:33:54,895::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:33:54,895::vdsm::98::vds::(run) <_MainThread(MainThread, started 140367274215168)> MainThread::INFO::2013-03-20 08:33:54,895::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:33:54,956::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:34:05,312::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: internal error client socket is closed MainThread::INFO::2013-03-20 08:34:05,314::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:34:05,314::vdsm::98::vds::(run) <_MainThread(MainThread, started 140430396319488)> MainThread::INFO::2013-03-20 08:34:05,314::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:34:05,376::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:34:15,631::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:34:15,634::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:34:15,634::vdsm::98::vds::(run) <_MainThread(MainThread, started 140303507937024)> MainThread::INFO::2013-03-20 08:34:15,634::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:34:15,695::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:34:26,056::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:34:26,058::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:34:26,058::vdsm::98::vds::(run) <_MainThread(MainThread, started 140379922302720)> MainThread::INFO::2013-03-20 08:34:26,059::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:34:26,121::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:34:36,485::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:34:36,487::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:34:36,487::vdsm::98::vds::(run) <_MainThread(MainThread, started 139730541491968)> MainThread::INFO::2013-03-20 08:34:36,487::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:34:36,549::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:34:46,907::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:34:46,909::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:34:46,909::vdsm::98::vds::(run) <_MainThread(MainThread, started 139842993878784)> MainThread::INFO::2013-03-20 08:34:46,910::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:34:46,971::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:34:57,336::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:34:57,338::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:34:57,338::vdsm::98::vds::(run) <_MainThread(MainThread, started 140263284279040)> MainThread::INFO::2013-03-20 08:34:57,338::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:34:57,400::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:35:07,764::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:35:07,766::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:35:07,766::vdsm::98::vds::(run) <_MainThread(MainThread, started 139857216329472)> MainThread::INFO::2013-03-20 08:35:07,766::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:35:07,830::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:35:18,187::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: internal error client socket is closed MainThread::INFO::2013-03-20 08:35:18,190::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:35:18,190::vdsm::98::vds::(run) <_MainThread(MainThread, started 140025369249536)> MainThread::INFO::2013-03-20 08:35:18,190::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:35:18,252::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:35:28,609::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: internal error client socket is closed MainThread::INFO::2013-03-20 08:35:28,611::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:35:28,611::vdsm::98::vds::(run) <_MainThread(MainThread, started 140538090141440)> MainThread::INFO::2013-03-20 08:35:28,611::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:35:28,673::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:35:39,025::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:35:39,027::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:35:39,027::vdsm::98::vds::(run) <_MainThread(MainThread, started 140099244349184)> MainThread::INFO::2013-03-20 08:35:39,027::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:35:39,088::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:35:49,445::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:35:49,447::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:35:49,447::vdsm::98::vds::(run) <_MainThread(MainThread, started 140106199635712)> MainThread::INFO::2013-03-20 08:35:49,447::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:35:49,508::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:35:59,864::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:35:59,867::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:35:59,867::vdsm::98::vds::(run) <_MainThread(MainThread, started 139962978518784)> MainThread::INFO::2013-03-20 08:35:59,867::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:35:59,930::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:36:10,282::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:36:10,284::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:36:10,284::vdsm::98::vds::(run) <_MainThread(MainThread, started 140298281182976)> MainThread::INFO::2013-03-20 08:36:10,284::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:36:10,346::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:36:20,705::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:36:20,707::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:36:20,707::vdsm::98::vds::(run) <_MainThread(MainThread, started 140457608591104)> MainThread::INFO::2013-03-20 08:36:20,707::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:36:20,769::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:36:31,128::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:36:31,131::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:36:31,131::vdsm::98::vds::(run) <_MainThread(MainThread, started 139849386391296)> MainThread::INFO::2013-03-20 08:36:31,131::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:36:31,192::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:36:41,553::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:36:41,556::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:36:41,556::vdsm::98::vds::(run) <_MainThread(MainThread, started 140119577020160)> MainThread::INFO::2013-03-20 08:36:41,556::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:36:41,619::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:36:51,982::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: internal error client socket is closed MainThread::INFO::2013-03-20 08:36:51,984::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:36:51,984::vdsm::98::vds::(run) <_MainThread(MainThread, started 140162775107328)> MainThread::INFO::2013-03-20 08:36:51,984::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:36:52,045::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:37:02,412::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:37:02,415::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:37:02,415::vdsm::98::vds::(run) <_MainThread(MainThread, started 140410531813120)> MainThread::INFO::2013-03-20 08:37:02,415::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:37:02,481::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:37:12,843::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:37:12,845::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:37:12,845::vdsm::98::vds::(run) <_MainThread(MainThread, started 140339423401728)> MainThread::INFO::2013-03-20 08:37:12,845::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:37:12,907::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:37:23,269::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:37:23,271::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:37:23,272::vdsm::98::vds::(run) <_MainThread(MainThread, started 139786576766720)> MainThread::INFO::2013-03-20 08:37:23,272::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:37:23,333::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:37:33,692::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:37:33,694::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:37:33,694::vdsm::98::vds::(run) <_MainThread(MainThread, started 140322661984000)> MainThread::INFO::2013-03-20 08:37:33,695::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:37:33,756::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:37:44,113::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: internal error client socket is closed MainThread::INFO::2013-03-20 08:37:44,115::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:37:44,116::vdsm::98::vds::(run) <_MainThread(MainThread, started 139776563586816)> MainThread::INFO::2013-03-20 08:37:44,116::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 08:37:44,177::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::ERROR::2013-03-20 08:37:54,399::vdsm::91::vds::(run) Exception raised Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 89, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 56, in serve_clients cif = clientIF.getInstance(log) File "/usr/share/vdsm/clientIF.py", line 126, in getInstance cls._instance = clientIF(log) File "/usr/share/vdsm/clientIF.py", line 74, in __init__ self._libvirt = libvirtconnection.get() File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 116, in get conn = utils.retry(libvirtOpenAuth, timeout=10, sleep=0.2) File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 934, in retry return func() File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth if ret is None:raise libvirtError('virConnectOpenAuth() failed') libvirtError: Cannot write data: Broken pipe MainThread::INFO::2013-03-20 08:37:54,406::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2013-03-20 08:37:54,406::vdsm::98::vds::(run) <_MainThread(MainThread, started 140197665949440)> MainThread::INFO::2013-03-20 08:37:54,406::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:11:56,668::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::DEBUG::2013-03-20 09:11:59,527::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'Storage' MainThread::DEBUG::2013-03-20 09:11:59,528::threadPool::33::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0 MainThread::DEBUG::2013-03-20 09:11:59,633::multipath::115::Storage.Multipath::(isEnabled) multipath Defaulting to False MainThread::DEBUG::2013-03-20 09:11:59,634::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /bin/cp /tmp/tmpvKl_NE /etc/multipath.conf' (cwd None) MainThread::DEBUG::2013-03-20 09:11:59,837::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 MainThread::DEBUG::2013-03-20 09:11:59,838::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/multipath -F' (cwd None) MainThread::DEBUG::2013-03-20 09:11:59,850::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 MainThread::DEBUG::2013-03-20 09:11:59,850::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/service multipathd restart' (cwd None) MainThread::DEBUG::2013-03-20 09:12:00,036::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 MainThread::DEBUG::2013-03-20 09:12:00,037::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None) MainThread::DEBUG::2013-03-20 09:12:00,203::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 MainThread::DEBUG::2013-03-20 09:12:00,204::hsm::426::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center' MainThread::DEBUG::2013-03-20 09:12:00,209::hsm::458::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt'] MainThread::DEBUG::2013-03-20 09:12:00,210::hsm::459::Storage.HSM::(__cleanStorageRepository) Mount list: [] MainThread::DEBUG::2013-03-20 09:12:00,210::hsm::461::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers MainThread::DEBUG::2013-03-20 09:12:00,211::hsm::504::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center' MainThread::INFO::2013-03-20 09:12:00,214::dispatcher::95::Storage.Dispatcher::(__init__) Starting StorageDispatcher... Thread-12::DEBUG::2013-03-20 09:12:00,219::lvm::334::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex MainThread::WARNING::2013-03-20 09:12:00,275::clientIF::196::vds::(_prepareMOM) MOM initialization failed and fall back to KsmMonitor MainThread::DEBUG::2013-03-20 09:12:00,275::clientIF::198::vds::(_prepareMOM) Details: Traceback (most recent call last): File "/usr/share/vdsm/clientIF.py", line 194, in _prepareMOM self.mom = MomThread(momconf) File "/usr/share/vdsm/momIF.py", line 34, in __init__ raise Exception("MOM is not available") Exception: MOM is not available Thread-12::DEBUG::2013-03-20 09:12:00,276::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/lvm pvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,size,vg_name,vg_uuid,pe_start,pe_count,pe_alloc_count,mda_count,dev_size' (cwd None) MainThread::DEBUG::2013-03-20 09:12:00,322::misc::83::Storage.Misc.excCmd::() '/usr/bin/pgrep -xf ksmd' (cwd None) MainThread::DEBUG::2013-03-20 09:12:00,455::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 MainThread::INFO::2013-03-20 09:12:00,512::ksm::43::vds::(__init__) starting ksm monitor thread, ksm pid is 39 KsmMonitor::DEBUG::2013-03-20 09:12:00,514::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/service ksmtuned start' (cwd None) MainThread::INFO::2013-03-20 09:12:00,530::vmChannels::139::vds::(settimeout) Setting channels' timeout to 30 seconds. Thread-12::DEBUG::2013-03-20 09:12:00,531::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 VM Channels Listener::INFO::2013-03-20 09:12:00,667::vmChannels::127::vds::(run) Starting VM channels listener thread. KsmMonitor::DEBUG::2013-03-20 09:12:00,693::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 KsmMonitor::DEBUG::2013-03-20 09:12:00,694::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/service ksm start' (cwd None) Thread-12::DEBUG::2013-03-20 09:12:00,694::lvm::359::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:12:00,703::lvm::368::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:12:00,704::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free' (cwd None) MainThread::WARNING::2013-03-20 09:12:00,704::clientIF::182::vds::(_prepareBindings) Unable to load the rest server module. Please make sure it is installed. MainThread::WARNING::2013-03-20 09:12:00,722::clientIF::188::vds::(_prepareBindings) Unable to load the json rpc server module. Please make sure it is installed. KsmMonitor::DEBUG::2013-03-20 09:12:00,750::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 Thread-12::DEBUG::2013-03-20 09:12:00,870::misc::83::Storage.Misc.excCmd::() SUCCESS: = ' No volume groups found\n'; = 0 Thread-12::DEBUG::2013-03-20 09:12:00,871::lvm::397::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:12:00,871::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,vg_name,attr,size,seg_start_pe,devices,tags' (cwd None) Thread-12::DEBUG::2013-03-20 09:12:01,000::misc::83::Storage.Misc.excCmd::() SUCCESS: = ' No volume groups found\n'; = 0 Thread-12::DEBUG::2013-03-20 09:12:01,000::misc::1025::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage) Thread-12::DEBUG::2013-03-20 09:12:01,000::misc::1027::SamplingMethod::(__call__) Got in to sampling method Thread-12::DEBUG::2013-03-20 09:12:01,001::misc::1025::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan) Thread-12::DEBUG::2013-03-20 09:12:01,001::misc::1027::SamplingMethod::(__call__) Got in to sampling method Thread-12::DEBUG::2013-03-20 09:12:01,001::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None) Thread-12::DEBUG::2013-03-20 09:12:01,249::misc::83::Storage.Misc.excCmd::() FAILED: = 'iscsiadm: No session found.\n'; = 21 Thread-12::DEBUG::2013-03-20 09:12:01,250::misc::1035::SamplingMethod::(__call__) Returning last result Thread-12::DEBUG::2013-03-20 09:12:01,250::supervdsm::117::SuperVdsmProxy::(_start) Launching Super Vdsm Thread-12::DEBUG::2013-03-20 09:12:01,250::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /usr/bin/python /usr/share/vdsm/supervdsmServer.py 9493ef7b-4bcb-4e9c-a7c2-68fbceeafd20 2218 /var/run/vdsm/svdsm.pid /var/run/vdsm/svdsm.time /var/run/vdsm/svdsm.sock 36' (cwd None) MainThread::DEBUG::2013-03-20 09:12:02,293::supervdsmServer::332::SuperVdsm.Server::(main) Making sure I'm root MainThread::DEBUG::2013-03-20 09:12:02,293::supervdsmServer::336::SuperVdsm.Server::(main) Parsing cmd args MainThread::DEBUG::2013-03-20 09:12:02,293::supervdsmServer::340::SuperVdsm.Server::(main) Creating PID and TIMESTAMP files: /var/run/vdsm/svdsm.pid, /var/run/vdsm/svdsm.time MainThread::DEBUG::2013-03-20 09:12:02,293::supervdsmServer::347::SuperVdsm.Server::(main) Cleaning old socket /var/run/vdsm/svdsm.sock MainThread::DEBUG::2013-03-20 09:12:02,294::supervdsmServer::351::SuperVdsm.Server::(main) Setting up keep alive thread MainThread::DEBUG::2013-03-20 09:12:02,294::supervdsmServer::359::SuperVdsm.Server::(main) Creating remote object manager MainThread::DEBUG::2013-03-20 09:12:02,295::supervdsmServer::371::SuperVdsm.Server::(main) Started serving super vdsm object Thread-12::DEBUG::2013-03-20 09:12:03,261::supervdsm::176::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm MainProcess|Thread-12::DEBUG::2013-03-20 09:12:03,360::misc::83::Storage.Misc.excCmd::() '/bin/dd of=/sys/class/scsi_host/host0/scan' (cwd None) MainProcess|Thread-12::DEBUG::2013-03-20 09:12:03,362::misc::83::Storage.Misc.excCmd::() '/bin/dd of=/sys/class/scsi_host/host1/scan' (cwd None) MainProcess|Thread-12::DEBUG::2013-03-20 09:12:03,364::iscsi::388::Storage.ISCSI::(forceIScsiScan) Performing SCSI scan, this will take up to 30 seconds Thread-12::DEBUG::2013-03-20 09:12:05,366::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/multipath' (cwd None) Thread-12::DEBUG::2013-03-20 09:12:05,672::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 Thread-12::DEBUG::2013-03-20 09:12:05,673::lvm::477::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:12:05,673::lvm::479::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:12:05,673::lvm::488::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:12:05,674::lvm::490::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:12:05,674::lvm::508::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:12:05,674::lvm::510::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:12:05,674::misc::1035::SamplingMethod::(__call__) Returning last result MainThread::INFO::2013-03-20 09:13:50,979::vmChannels::135::vds::(stop) VM channels listener was stopped. MainThread::DEBUG::2013-03-20 09:13:50,984::task::568::TaskManager.Task::(_updateState) Task=`5dd28e95-e840-4eea-926c-f2373087c44d`::moving from state init -> state preparing MainThread::INFO::2013-03-20 09:13:50,984::logUtils::37::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None) Thread-11::DEBUG::2013-03-20 09:13:50,985::storageServer::674::ConnectionMonitor::(_monitorConnections) Monitoring stopped MainThread::DEBUG::2013-03-20 09:13:51,066::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks MainThread::INFO::2013-03-20 09:13:51,066::logUtils::39::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None MainThread::DEBUG::2013-03-20 09:13:51,066::task::1151::TaskManager.Task::(prepare) Task=`5dd28e95-e840-4eea-926c-f2373087c44d`::finished: None MainThread::DEBUG::2013-03-20 09:13:51,067::task::568::TaskManager.Task::(_updateState) Task=`5dd28e95-e840-4eea-926c-f2373087c44d`::moving from state preparing -> state finished MainThread::DEBUG::2013-03-20 09:13:51,067::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} MainThread::DEBUG::2013-03-20 09:13:51,067::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} MainThread::DEBUG::2013-03-20 09:13:51,067::task::957::TaskManager.Task::(_decref) Task=`5dd28e95-e840-4eea-926c-f2373087c44d`::ref 0 aborting False MainThread::INFO::2013-03-20 09:13:51,067::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 13 other threads... MainThread::INFO::2013-03-20 09:13:51,067::vdsm::98::vds::(run) <_MainThread(MainThread, started 140203490203392)> MainThread::INFO::2013-03-20 09:13:51,067::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:13:51,067::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:13:51,068::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:13:51,068::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:13:51,068::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:13:51,068::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:13:51,068::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:13:51,068::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:13:51,068::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:13:51,068::vmChannels::135::vds::(stop) VM channels listener was stopped. MainThread::INFO::2013-03-20 09:13:51,068::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:13:51,069::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:13:51,069::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:13:51,069::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:34:33,374::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::DEBUG::2013-03-20 09:34:35,370::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'Storage' MainThread::DEBUG::2013-03-20 09:34:35,370::threadPool::33::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0 MainThread::WARNING::2013-03-20 09:34:35,454::fileUtils::184::fileUtils::(createdir) Dir /rhev/data-center/mnt already exists MainThread::DEBUG::2013-03-20 09:34:35,612::supervdsm::117::SuperVdsmProxy::(_start) Launching Super Vdsm MainThread::DEBUG::2013-03-20 09:34:35,613::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /usr/bin/python /usr/share/vdsm/supervdsmServer.py 70b88ed8-4c15-4d00-911b-82dc6ad6a538 2250 /var/run/vdsm/svdsm.pid /var/run/vdsm/svdsm.time /var/run/vdsm/svdsm.sock 36' (cwd None) MainThread::DEBUG::2013-03-20 09:34:36,834::supervdsmServer::332::SuperVdsm.Server::(main) Making sure I'm root MainThread::DEBUG::2013-03-20 09:34:36,834::supervdsmServer::336::SuperVdsm.Server::(main) Parsing cmd args MainThread::DEBUG::2013-03-20 09:34:36,834::supervdsmServer::340::SuperVdsm.Server::(main) Creating PID and TIMESTAMP files: /var/run/vdsm/svdsm.pid, /var/run/vdsm/svdsm.time MainThread::DEBUG::2013-03-20 09:34:36,834::supervdsmServer::347::SuperVdsm.Server::(main) Cleaning old socket /var/run/vdsm/svdsm.sock MainThread::DEBUG::2013-03-20 09:34:36,834::supervdsmServer::351::SuperVdsm.Server::(main) Setting up keep alive thread MainThread::DEBUG::2013-03-20 09:34:36,835::supervdsmServer::359::SuperVdsm.Server::(main) Creating remote object manager MainThread::DEBUG::2013-03-20 09:34:36,836::supervdsmServer::371::SuperVdsm.Server::(main) Started serving super vdsm object MainThread::DEBUG::2013-03-20 09:34:37,680::supervdsm::176::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm MainThread::DEBUG::2013-03-20 09:34:37,717::multipath::106::Storage.Multipath::(isEnabled) Current revision of multipath.conf detected, preserving MainThread::DEBUG::2013-03-20 09:34:37,717::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None) MainThread::DEBUG::2013-03-20 09:34:37,865::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 MainThread::DEBUG::2013-03-20 09:34:37,866::hsm::426::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center' MainThread::DEBUG::2013-03-20 09:34:37,869::hsm::458::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt'] MainThread::DEBUG::2013-03-20 09:34:37,869::hsm::459::Storage.HSM::(__cleanStorageRepository) Mount list: [] MainThread::DEBUG::2013-03-20 09:34:37,869::hsm::461::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers MainThread::DEBUG::2013-03-20 09:34:37,870::hsm::504::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center' MainThread::INFO::2013-03-20 09:34:37,871::dispatcher::95::Storage.Dispatcher::(__init__) Starting StorageDispatcher... Thread-12::DEBUG::2013-03-20 09:34:37,871::lvm::334::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:34:37,880::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/lvm pvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,size,vg_name,vg_uuid,pe_start,pe_count,pe_alloc_count,mda_count,dev_size' (cwd None) MainThread::WARNING::2013-03-20 09:34:37,893::clientIF::196::vds::(_prepareMOM) MOM initialization failed and fall back to KsmMonitor MainThread::DEBUG::2013-03-20 09:34:37,894::clientIF::198::vds::(_prepareMOM) Details: Traceback (most recent call last): File "/usr/share/vdsm/clientIF.py", line 194, in _prepareMOM self.mom = MomThread(momconf) File "/usr/share/vdsm/momIF.py", line 34, in __init__ raise Exception("MOM is not available") Exception: MOM is not available MainThread::DEBUG::2013-03-20 09:34:37,955::misc::83::Storage.Misc.excCmd::() '/usr/bin/pgrep -xf ksmd' (cwd None) MainThread::DEBUG::2013-03-20 09:34:38,040::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 MainThread::INFO::2013-03-20 09:34:38,040::ksm::43::vds::(__init__) starting ksm monitor thread, ksm pid is 39 KsmMonitor::DEBUG::2013-03-20 09:34:38,040::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/service ksmtuned start' (cwd None) MainThread::INFO::2013-03-20 09:34:38,041::vmChannels::139::vds::(settimeout) Setting channels' timeout to 30 seconds. VM Channels Listener::INFO::2013-03-20 09:34:38,049::vmChannels::127::vds::(run) Starting VM channels listener thread. Thread-12::DEBUG::2013-03-20 09:34:38,232::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 Thread-12::DEBUG::2013-03-20 09:34:38,232::lvm::359::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:34:38,233::lvm::368::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:34:38,233::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free' (cwd None) KsmMonitor::DEBUG::2013-03-20 09:34:38,332::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 KsmMonitor::DEBUG::2013-03-20 09:34:38,332::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/service ksm start' (cwd None) MainThread::WARNING::2013-03-20 09:34:38,339::clientIF::182::vds::(_prepareBindings) Unable to load the rest server module. Please make sure it is installed. MainThread::WARNING::2013-03-20 09:34:38,339::clientIF::188::vds::(_prepareBindings) Unable to load the json rpc server module. Please make sure it is installed. Thread-12::DEBUG::2013-03-20 09:34:38,348::misc::83::Storage.Misc.excCmd::() SUCCESS: = ' No volume groups found\n'; = 0 Thread-12::DEBUG::2013-03-20 09:34:38,348::lvm::397::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:34:38,349::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,vg_name,attr,size,seg_start_pe,devices,tags' (cwd None) KsmMonitor::DEBUG::2013-03-20 09:34:38,373::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 Thread-12::DEBUG::2013-03-20 09:34:38,468::misc::83::Storage.Misc.excCmd::() SUCCESS: = ' No volume groups found\n'; = 0 Thread-12::DEBUG::2013-03-20 09:34:38,468::misc::1025::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage) Thread-12::DEBUG::2013-03-20 09:34:38,468::misc::1027::SamplingMethod::(__call__) Got in to sampling method Thread-12::DEBUG::2013-03-20 09:34:38,468::misc::1025::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan) Thread-12::DEBUG::2013-03-20 09:34:38,469::misc::1027::SamplingMethod::(__call__) Got in to sampling method Thread-12::DEBUG::2013-03-20 09:34:38,469::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None) Thread-12::DEBUG::2013-03-20 09:34:38,790::misc::83::Storage.Misc.excCmd::() FAILED: = 'iscsiadm: No session found.\n'; = 21 Thread-12::DEBUG::2013-03-20 09:34:38,791::misc::1035::SamplingMethod::(__call__) Returning last result MainProcess|Thread-12::DEBUG::2013-03-20 09:34:38,793::misc::83::Storage.Misc.excCmd::() '/bin/dd of=/sys/class/scsi_host/host0/scan' (cwd None) MainProcess|Thread-12::DEBUG::2013-03-20 09:34:38,795::misc::83::Storage.Misc.excCmd::() '/bin/dd of=/sys/class/scsi_host/host1/scan' (cwd None) MainProcess|Thread-12::DEBUG::2013-03-20 09:34:38,797::iscsi::388::Storage.ISCSI::(forceIScsiScan) Performing SCSI scan, this will take up to 30 seconds Thread-12::DEBUG::2013-03-20 09:34:40,799::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/multipath' (cwd None) Thread-12::DEBUG::2013-03-20 09:34:40,934::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 Thread-12::DEBUG::2013-03-20 09:34:40,935::lvm::477::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:34:40,935::lvm::479::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:34:40,935::lvm::488::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:34:40,935::lvm::490::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:34:40,936::lvm::508::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:34:40,936::lvm::510::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:34:40,936::misc::1035::SamplingMethod::(__call__) Returning last result Thread-12::WARNING::2013-03-20 09:34:40,936::fileUtils::184::fileUtils::(createdir) Dir /rhev/data-center/hsm-tasks already exists Thread-14::DEBUG::2013-03-20 09:34:52,027::BindingXMLRPC::903::vds::(wrapper) client [127.0.0.1]::call getCapabilities with () {} Thread-14::DEBUG::2013-03-20 09:34:52,352::caps::343::root::(_getKeyPackages) rpm package mom not found Thread-14::DEBUG::2013-03-20 09:34:52,361::BindingXMLRPC::910::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:256c354993be'}], 'FC': []}, 'packages2': {'kernel': {'release': '358.2.1.el6.x86_64', 'buildtime': 1363156009.0, 'version': '2.6.32'}, 'spice-server': {'release': '12.el6', 'buildtime': 1361511255L, 'version': '0.12.0'}, 'vdsm': {'release': '0.11.gitee9833b.el6.centos.alt', 'buildtime': 1354579654L, 'version': '4.10.2'}, 'qemu-kvm': {'release': '2.355.0.1.el6.centos.2', 'buildtime': 1363012845L, 'version': '0.12.1.2'}, 'libvirt': {'release': '18.el6', 'buildtime': 1361515221L, 'version': '0.10.2'}, 'qemu-img': {'release': '2.355.0.1.el6.centos.2', 'buildtime': 1363012845L, 'version': '0.12.1.2'}}, 'cpuModel': 'Intel(R) Core(TM)2 Duo CPU E7500 @ 2.93GHz', 'hooks': {}, 'vmTypes': ['kvm'], 'supportedProtocols': ['2.2', '2.3'], 'networks': {'ovirtmgmt': {'iface': 'ovirtmgmt', 'addr': '192.168.5.193', 'cfg': {'PEERROUTES': 'yes', 'IPV6INIT': 'no', 'DEFROUTE': 'yes', 'PEERDNS': 'yes', 'IPV4_FAILURE_FATAL': 'yes', 'DELAY': '40', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'STP': 'no', 'DEVICE': 'ovirtmgmt', 'TYPE': 'bridge', 'ONBOOT': 'yes', 'NAME': 'System eth0'}, 'mtu': '1500', 'netmask': '255.255.255.0', 'stp': 'off', 'bridged': True, 'gateway': '192.168.5.25', 'ports': ['eth0']}}, 'bridges': {'ovirtmgmt': {'addr': '192.168.5.193', 'cfg': {'PEERROUTES': 'yes', 'IPV6INIT': 'no', 'DEFROUTE': 'yes', 'PEERDNS': 'yes', 'IPV4_FAILURE_FATAL': 'yes', 'DELAY': '40', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'STP': 'no', 'DEVICE': 'ovirtmgmt', 'TYPE': 'bridge', 'ONBOOT': 'yes', 'NAME': 'System eth0'}, 'mtu': '1500', 'netmask': '255.255.255.0', 'stp': 'off', 'ports': ['eth0']}}, 'uuid': '4C4C4544-0056-4C10-804A-B7C04F4A4D31_b8:ac:6f:b5:30:51', 'lastClientIface': 'ovirtmgmt', 'nics': {'eth0': {'addr': '', 'cfg': {'HWADDR': 'B8:AC:6F:B5:30:51', 'BRIDGE': 'ovirtmgmt', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'none', 'DEVICE': 'eth0', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': 'b8:ac:6f:b5:30:51', 'speed': 1000}}, 'software_revision': '0.11', 'clusterLevels': ['3.0', '3.1', '3.2'], 'cpuFlags': u'fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,pse36,clflush,dts,acpi,mmx,fxsr,sse,sse2,ss,ht,tm,pbe,syscall,nx,lm,constant_tsc,arch_perfmon,pebs,bts,rep_good,aperfmperf,pni,dtes64,monitor,ds_cpl,vmx,est,tm2,ssse3,cx16,xtpr,pdcm,sse4_1,xsave,lahf_lm,dts,tpr_shadow,vnmi,flexpriority,model_Conroe,model_coreduo,model_core2duo,model_Penryn,model_n270', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:256c354993be', 'netConfigDirty': 'False', 'supportedENGINEs': ['3.0', '3.1'], 'reservedMem': '321', 'bondings': {'bond4': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond0': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}}, 'software_version': '4.10', 'memSize': '3831', 'cpuSpeed': '2925.834', 'cpuSockets': '1', 'vlans': {}, 'cpuCores': '2', 'kvmEnabled': 'true', 'guestOverhead': '65', 'management_ip': '', 'version_name': 'Snow Man', 'emulatedMachines': [u'rhel6.4.0', u'pc', u'rhel6.3.0', u'rhel6.2.0', u'rhel6.1.0', u'rhel6.0.0', u'rhel5.5.0', u'rhel5.4.4', u'rhel5.4.0'], 'operatingSystem': {'release': '4.el6.centos.10', 'version': '6', 'name': 'RHEL'}, 'lastClient': '0.0.0.0'}} Thread-15::DEBUG::2013-03-20 09:34:52,625::BindingXMLRPC::903::vds::(wrapper) client [127.0.0.1]::call getCapabilities with () {} Thread-15::DEBUG::2013-03-20 09:34:52,644::caps::343::root::(_getKeyPackages) rpm package mom not found Thread-15::DEBUG::2013-03-20 09:34:52,645::BindingXMLRPC::910::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:256c354993be'}], 'FC': []}, 'packages2': {'kernel': {'release': '358.2.1.el6.x86_64', 'buildtime': 1363156009.0, 'version': '2.6.32'}, 'spice-server': {'release': '12.el6', 'buildtime': 1361511255L, 'version': '0.12.0'}, 'vdsm': {'release': '0.11.gitee9833b.el6.centos.alt', 'buildtime': 1354579654L, 'version': '4.10.2'}, 'qemu-kvm': {'release': '2.355.0.1.el6.centos.2', 'buildtime': 1363012845L, 'version': '0.12.1.2'}, 'libvirt': {'release': '18.el6', 'buildtime': 1361515221L, 'version': '0.10.2'}, 'qemu-img': {'release': '2.355.0.1.el6.centos.2', 'buildtime': 1363012845L, 'version': '0.12.1.2'}}, 'cpuModel': 'Intel(R) Core(TM)2 Duo CPU E7500 @ 2.93GHz', 'hooks': {}, 'vmTypes': ['kvm'], 'supportedProtocols': ['2.2', '2.3'], 'networks': {'ovirtmgmt': {'iface': 'ovirtmgmt', 'addr': '192.168.5.193', 'cfg': {'PEERROUTES': 'yes', 'IPV6INIT': 'no', 'DEFROUTE': 'yes', 'PEERDNS': 'yes', 'IPV4_FAILURE_FATAL': 'yes', 'DELAY': '40', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'STP': 'no', 'DEVICE': 'ovirtmgmt', 'TYPE': 'bridge', 'ONBOOT': 'yes', 'NAME': 'System eth0'}, 'mtu': '1500', 'netmask': '255.255.255.0', 'stp': 'off', 'bridged': True, 'gateway': '192.168.5.25', 'ports': ['eth0']}}, 'bridges': {'ovirtmgmt': {'addr': '192.168.5.193', 'cfg': {'PEERROUTES': 'yes', 'IPV6INIT': 'no', 'DEFROUTE': 'yes', 'PEERDNS': 'yes', 'IPV4_FAILURE_FATAL': 'yes', 'DELAY': '40', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'STP': 'no', 'DEVICE': 'ovirtmgmt', 'TYPE': 'bridge', 'ONBOOT': 'yes', 'NAME': 'System eth0'}, 'mtu': '1500', 'netmask': '255.255.255.0', 'stp': 'off', 'ports': ['eth0']}}, 'uuid': '4C4C4544-0056-4C10-804A-B7C04F4A4D31_b8:ac:6f:b5:30:51', 'lastClientIface': 'ovirtmgmt', 'nics': {'eth0': {'addr': '', 'cfg': {'HWADDR': 'B8:AC:6F:B5:30:51', 'BRIDGE': 'ovirtmgmt', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'none', 'DEVICE': 'eth0', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': 'b8:ac:6f:b5:30:51', 'speed': 1000}}, 'software_revision': '0.11', 'clusterLevels': ['3.0', '3.1', '3.2'], 'cpuFlags': u'fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,pse36,clflush,dts,acpi,mmx,fxsr,sse,sse2,ss,ht,tm,pbe,syscall,nx,lm,constant_tsc,arch_perfmon,pebs,bts,rep_good,aperfmperf,pni,dtes64,monitor,ds_cpl,vmx,est,tm2,ssse3,cx16,xtpr,pdcm,sse4_1,xsave,lahf_lm,dts,tpr_shadow,vnmi,flexpriority,model_Conroe,model_coreduo,model_core2duo,model_Penryn,model_n270', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:256c354993be', 'netConfigDirty': 'False', 'supportedENGINEs': ['3.0', '3.1'], 'reservedMem': '321', 'bondings': {'bond4': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond0': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}}, 'software_version': '4.10', 'memSize': '3831', 'cpuSpeed': '2925.834', 'cpuSockets': '1', 'vlans': {}, 'cpuCores': '2', 'kvmEnabled': 'true', 'guestOverhead': '65', 'management_ip': '', 'version_name': 'Snow Man', 'emulatedMachines': [u'rhel6.4.0', u'pc', u'rhel6.3.0', u'rhel6.2.0', u'rhel6.1.0', u'rhel6.0.0', u'rhel5.5.0', u'rhel5.4.4', u'rhel5.4.0'], 'operatingSystem': {'release': '4.el6.centos.10', 'version': '6', 'name': 'RHEL'}, 'lastClient': '127.0.0.1'}} Thread-21::DEBUG::2013-03-20 09:35:03,595::task::568::TaskManager.Task::(_updateState) Task=`1eacefdc-4070-4ef9-b1e2-80eda3575868`::moving from state init -> state preparing Thread-21::INFO::2013-03-20 09:35:03,595::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-21::INFO::2013-03-20 09:35:03,595::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} Thread-21::DEBUG::2013-03-20 09:35:03,595::task::1151::TaskManager.Task::(prepare) Task=`1eacefdc-4070-4ef9-b1e2-80eda3575868`::finished: {} Thread-21::DEBUG::2013-03-20 09:35:03,596::task::568::TaskManager.Task::(_updateState) Task=`1eacefdc-4070-4ef9-b1e2-80eda3575868`::moving from state preparing -> state finished Thread-21::DEBUG::2013-03-20 09:35:03,596::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-21::DEBUG::2013-03-20 09:35:03,596::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-21::DEBUG::2013-03-20 09:35:03,596::task::957::TaskManager.Task::(_decref) Task=`1eacefdc-4070-4ef9-b1e2-80eda3575868`::ref 0 aborting False Thread-27::DEBUG::2013-03-20 09:35:13,962::task::568::TaskManager.Task::(_updateState) Task=`04bf7fc9-6361-4fc4-b252-43b421404344`::moving from state init -> state preparing Thread-27::INFO::2013-03-20 09:35:13,963::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-27::INFO::2013-03-20 09:35:13,963::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} Thread-27::DEBUG::2013-03-20 09:35:13,963::task::1151::TaskManager.Task::(prepare) Task=`04bf7fc9-6361-4fc4-b252-43b421404344`::finished: {} Thread-27::DEBUG::2013-03-20 09:35:13,963::task::568::TaskManager.Task::(_updateState) Task=`04bf7fc9-6361-4fc4-b252-43b421404344`::moving from state preparing -> state finished Thread-27::DEBUG::2013-03-20 09:35:13,963::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-27::DEBUG::2013-03-20 09:35:13,963::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-27::DEBUG::2013-03-20 09:35:13,963::task::957::TaskManager.Task::(_decref) Task=`04bf7fc9-6361-4fc4-b252-43b421404344`::ref 0 aborting False Thread-33::DEBUG::2013-03-20 09:35:24,306::task::568::TaskManager.Task::(_updateState) Task=`f63d0710-894c-46ba-a991-e5b36126ead7`::moving from state init -> state preparing Thread-33::INFO::2013-03-20 09:35:24,306::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-33::INFO::2013-03-20 09:35:24,306::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} Thread-33::DEBUG::2013-03-20 09:35:24,306::task::1151::TaskManager.Task::(prepare) Task=`f63d0710-894c-46ba-a991-e5b36126ead7`::finished: {} Thread-33::DEBUG::2013-03-20 09:35:24,306::task::568::TaskManager.Task::(_updateState) Task=`f63d0710-894c-46ba-a991-e5b36126ead7`::moving from state preparing -> state finished Thread-33::DEBUG::2013-03-20 09:35:24,306::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-33::DEBUG::2013-03-20 09:35:24,307::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-33::DEBUG::2013-03-20 09:35:24,307::task::957::TaskManager.Task::(_decref) Task=`f63d0710-894c-46ba-a991-e5b36126ead7`::ref 0 aborting False Thread-39::DEBUG::2013-03-20 09:35:34,654::task::568::TaskManager.Task::(_updateState) Task=`3bd3e491-db21-4378-9b4a-8083d7206883`::moving from state init -> state preparing Thread-39::INFO::2013-03-20 09:35:34,654::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-39::INFO::2013-03-20 09:35:34,654::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} Thread-39::DEBUG::2013-03-20 09:35:34,655::task::1151::TaskManager.Task::(prepare) Task=`3bd3e491-db21-4378-9b4a-8083d7206883`::finished: {} Thread-39::DEBUG::2013-03-20 09:35:34,655::task::568::TaskManager.Task::(_updateState) Task=`3bd3e491-db21-4378-9b4a-8083d7206883`::moving from state preparing -> state finished Thread-39::DEBUG::2013-03-20 09:35:34,655::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-39::DEBUG::2013-03-20 09:35:34,655::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-39::DEBUG::2013-03-20 09:35:34,655::task::957::TaskManager.Task::(_decref) Task=`3bd3e491-db21-4378-9b4a-8083d7206883`::ref 0 aborting False Thread-45::DEBUG::2013-03-20 09:35:44,989::task::568::TaskManager.Task::(_updateState) Task=`d889ea04-0b05-4894-9a75-753ea493c8a5`::moving from state init -> state preparing Thread-45::INFO::2013-03-20 09:35:44,994::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-45::INFO::2013-03-20 09:35:44,994::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} Thread-45::DEBUG::2013-03-20 09:35:44,994::task::1151::TaskManager.Task::(prepare) Task=`d889ea04-0b05-4894-9a75-753ea493c8a5`::finished: {} Thread-45::DEBUG::2013-03-20 09:35:44,994::task::568::TaskManager.Task::(_updateState) Task=`d889ea04-0b05-4894-9a75-753ea493c8a5`::moving from state preparing -> state finished Thread-45::DEBUG::2013-03-20 09:35:44,995::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-45::DEBUG::2013-03-20 09:35:44,995::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-45::DEBUG::2013-03-20 09:35:44,995::task::957::TaskManager.Task::(_decref) Task=`d889ea04-0b05-4894-9a75-753ea493c8a5`::ref 0 aborting False MainThread::INFO::2013-03-20 09:35:47,058::vmChannels::135::vds::(stop) VM channels listener was stopped. MainThread::DEBUG::2013-03-20 09:35:47,063::task::568::TaskManager.Task::(_updateState) Task=`e1afe23e-2c79-4910-ac2a-56da2329bfce`::moving from state init -> state preparing MainThread::INFO::2013-03-20 09:35:47,063::logUtils::37::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None) Thread-11::DEBUG::2013-03-20 09:35:47,064::storageServer::674::ConnectionMonitor::(_monitorConnections) Monitoring stopped MainThread::DEBUG::2013-03-20 09:35:47,141::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks MainThread::INFO::2013-03-20 09:35:47,142::logUtils::39::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None MainThread::DEBUG::2013-03-20 09:35:47,142::task::1151::TaskManager.Task::(prepare) Task=`e1afe23e-2c79-4910-ac2a-56da2329bfce`::finished: None MainThread::DEBUG::2013-03-20 09:35:47,142::task::568::TaskManager.Task::(_updateState) Task=`e1afe23e-2c79-4910-ac2a-56da2329bfce`::moving from state preparing -> state finished MainThread::DEBUG::2013-03-20 09:35:47,143::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} MainThread::DEBUG::2013-03-20 09:35:47,143::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} MainThread::DEBUG::2013-03-20 09:35:47,143::task::957::TaskManager.Task::(_decref) Task=`e1afe23e-2c79-4910-ac2a-56da2329bfce`::ref 0 aborting False MainThread::INFO::2013-03-20 09:35:47,143::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 13 other threads... MainThread::INFO::2013-03-20 09:35:47,143::vdsm::98::vds::(run) <_MainThread(MainThread, started 139704480237312)> MainThread::INFO::2013-03-20 09:35:47,143::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:35:47,143::vmChannels::135::vds::(stop) VM channels listener was stopped. MainThread::INFO::2013-03-20 09:35:47,143::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:35:47,144::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:35:47,144::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:35:47,144::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:35:47,144::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:35:47,144::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:35:47,144::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:35:47,144::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:35:47,144::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:35:47,144::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:35:47,145::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:35:47,145::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:36:50,540::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::DEBUG::2013-03-20 09:36:52,111::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'Storage' MainThread::DEBUG::2013-03-20 09:36:52,112::threadPool::33::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0 MainThread::WARNING::2013-03-20 09:36:52,195::fileUtils::184::fileUtils::(createdir) Dir /rhev/data-center/mnt already exists MainThread::DEBUG::2013-03-20 09:36:52,358::supervdsm::117::SuperVdsmProxy::(_start) Launching Super Vdsm MainThread::DEBUG::2013-03-20 09:36:52,358::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /usr/bin/python /usr/share/vdsm/supervdsmServer.py 77624fc0-d424-4c5e-bf29-87407929db49 2235 /var/run/vdsm/svdsm.pid /var/run/vdsm/svdsm.time /var/run/vdsm/svdsm.sock 36' (cwd None) MainThread::DEBUG::2013-03-20 09:36:53,728::supervdsmServer::332::SuperVdsm.Server::(main) Making sure I'm root MainThread::DEBUG::2013-03-20 09:36:53,729::supervdsmServer::336::SuperVdsm.Server::(main) Parsing cmd args MainThread::DEBUG::2013-03-20 09:36:53,729::supervdsmServer::340::SuperVdsm.Server::(main) Creating PID and TIMESTAMP files: /var/run/vdsm/svdsm.pid, /var/run/vdsm/svdsm.time MainThread::DEBUG::2013-03-20 09:36:53,729::supervdsmServer::347::SuperVdsm.Server::(main) Cleaning old socket /var/run/vdsm/svdsm.sock MainThread::DEBUG::2013-03-20 09:36:53,729::supervdsmServer::351::SuperVdsm.Server::(main) Setting up keep alive thread MainThread::DEBUG::2013-03-20 09:36:53,730::supervdsmServer::359::SuperVdsm.Server::(main) Creating remote object manager MainThread::DEBUG::2013-03-20 09:36:53,732::supervdsmServer::371::SuperVdsm.Server::(main) Started serving super vdsm object MainThread::DEBUG::2013-03-20 09:36:54,445::supervdsm::176::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm MainThread::DEBUG::2013-03-20 09:36:54,461::multipath::106::Storage.Multipath::(isEnabled) Current revision of multipath.conf detected, preserving MainThread::DEBUG::2013-03-20 09:36:54,461::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None) MainThread::DEBUG::2013-03-20 09:36:54,618::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 MainThread::DEBUG::2013-03-20 09:36:54,619::hsm::426::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center' MainThread::DEBUG::2013-03-20 09:36:54,622::hsm::458::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt'] MainThread::DEBUG::2013-03-20 09:36:54,622::hsm::459::Storage.HSM::(__cleanStorageRepository) Mount list: [] MainThread::DEBUG::2013-03-20 09:36:54,622::hsm::461::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers MainThread::DEBUG::2013-03-20 09:36:54,623::hsm::504::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center' MainThread::INFO::2013-03-20 09:36:54,626::dispatcher::95::Storage.Dispatcher::(__init__) Starting StorageDispatcher... Thread-12::DEBUG::2013-03-20 09:36:54,628::lvm::334::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex MainThread::WARNING::2013-03-20 09:36:54,638::clientIF::196::vds::(_prepareMOM) MOM initialization failed and fall back to KsmMonitor MainThread::DEBUG::2013-03-20 09:36:54,644::clientIF::198::vds::(_prepareMOM) Details: Traceback (most recent call last): File "/usr/share/vdsm/clientIF.py", line 194, in _prepareMOM self.mom = MomThread(momconf) File "/usr/share/vdsm/momIF.py", line 34, in __init__ raise Exception("MOM is not available") Exception: MOM is not available MainThread::DEBUG::2013-03-20 09:36:54,696::misc::83::Storage.Misc.excCmd::() '/usr/bin/pgrep -xf ksmd' (cwd None) Thread-12::DEBUG::2013-03-20 09:36:54,644::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/lvm pvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,size,vg_name,vg_uuid,pe_start,pe_count,pe_alloc_count,mda_count,dev_size' (cwd None) MainThread::DEBUG::2013-03-20 09:36:54,741::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 MainThread::INFO::2013-03-20 09:36:54,741::ksm::43::vds::(__init__) starting ksm monitor thread, ksm pid is 39 KsmMonitor::DEBUG::2013-03-20 09:36:54,747::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/service ksmtuned start' (cwd None) MainThread::INFO::2013-03-20 09:36:54,758::vmChannels::139::vds::(settimeout) Setting channels' timeout to 30 seconds. VM Channels Listener::INFO::2013-03-20 09:36:54,760::vmChannels::127::vds::(run) Starting VM channels listener thread. KsmMonitor::DEBUG::2013-03-20 09:36:54,857::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 MainThread::WARNING::2013-03-20 09:36:54,857::clientIF::182::vds::(_prepareBindings) Unable to load the rest server module. Please make sure it is installed. KsmMonitor::DEBUG::2013-03-20 09:36:54,858::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/service ksm start' (cwd None) MainThread::WARNING::2013-03-20 09:36:54,858::clientIF::188::vds::(_prepareBindings) Unable to load the json rpc server module. Please make sure it is installed. Thread-12::DEBUG::2013-03-20 09:36:54,899::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 Thread-12::DEBUG::2013-03-20 09:36:54,900::lvm::359::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:36:54,900::lvm::368::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:36:54,900::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free' (cwd None) KsmMonitor::DEBUG::2013-03-20 09:36:54,927::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 Thread-12::DEBUG::2013-03-20 09:36:55,033::misc::83::Storage.Misc.excCmd::() SUCCESS: = ' No volume groups found\n'; = 0 Thread-12::DEBUG::2013-03-20 09:36:55,079::lvm::397::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:36:55,080::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,vg_name,attr,size,seg_start_pe,devices,tags' (cwd None) Thread-12::DEBUG::2013-03-20 09:36:55,187::misc::83::Storage.Misc.excCmd::() SUCCESS: = ' No volume groups found\n'; = 0 Thread-12::DEBUG::2013-03-20 09:36:55,188::misc::1025::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage) Thread-12::DEBUG::2013-03-20 09:36:55,188::misc::1027::SamplingMethod::(__call__) Got in to sampling method Thread-12::DEBUG::2013-03-20 09:36:55,188::misc::1025::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan) Thread-12::DEBUG::2013-03-20 09:36:55,188::misc::1027::SamplingMethod::(__call__) Got in to sampling method Thread-12::DEBUG::2013-03-20 09:36:55,188::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None) Thread-12::DEBUG::2013-03-20 09:36:55,292::misc::83::Storage.Misc.excCmd::() FAILED: = 'iscsiadm: No session found.\n'; = 21 Thread-12::DEBUG::2013-03-20 09:36:55,293::misc::1035::SamplingMethod::(__call__) Returning last result MainProcess|Thread-12::DEBUG::2013-03-20 09:36:55,295::misc::83::Storage.Misc.excCmd::() '/bin/dd of=/sys/class/scsi_host/host0/scan' (cwd None) MainProcess|Thread-12::DEBUG::2013-03-20 09:36:55,298::misc::83::Storage.Misc.excCmd::() '/bin/dd of=/sys/class/scsi_host/host1/scan' (cwd None) MainProcess|Thread-12::DEBUG::2013-03-20 09:36:55,303::iscsi::388::Storage.ISCSI::(forceIScsiScan) Performing SCSI scan, this will take up to 30 seconds Thread-12::DEBUG::2013-03-20 09:36:57,306::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/multipath' (cwd None) Thread-12::DEBUG::2013-03-20 09:36:57,491::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 Thread-12::DEBUG::2013-03-20 09:36:57,492::lvm::477::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:36:57,492::lvm::479::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:36:57,492::lvm::488::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:36:57,492::lvm::490::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:36:57,493::lvm::508::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:36:57,493::lvm::510::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:36:57,493::misc::1035::SamplingMethod::(__call__) Returning last result Thread-12::WARNING::2013-03-20 09:36:57,493::fileUtils::184::fileUtils::(createdir) Dir /rhev/data-center/hsm-tasks already exists Thread-14::DEBUG::2013-03-20 09:37:08,818::BindingXMLRPC::903::vds::(wrapper) client [127.0.0.1]::call getCapabilities with () {} Thread-14::DEBUG::2013-03-20 09:37:09,201::caps::343::root::(_getKeyPackages) rpm package mom not found Thread-14::DEBUG::2013-03-20 09:37:09,212::BindingXMLRPC::910::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:256c354993be'}], 'FC': []}, 'packages2': {'kernel': {'release': '358.2.1.el6.x86_64', 'buildtime': 1363156009.0, 'version': '2.6.32'}, 'spice-server': {'release': '12.el6', 'buildtime': 1361511255L, 'version': '0.12.0'}, 'vdsm': {'release': '0.11.gitee9833b.el6.centos.alt', 'buildtime': 1354579654L, 'version': '4.10.2'}, 'qemu-kvm': {'release': '2.355.0.1.el6.centos.2', 'buildtime': 1363012845L, 'version': '0.12.1.2'}, 'libvirt': {'release': '18.el6', 'buildtime': 1361515221L, 'version': '0.10.2'}, 'qemu-img': {'release': '2.355.0.1.el6.centos.2', 'buildtime': 1363012845L, 'version': '0.12.1.2'}}, 'cpuModel': 'Intel(R) Core(TM)2 Duo CPU E7500 @ 2.93GHz', 'hooks': {}, 'vmTypes': ['kvm'], 'supportedProtocols': ['2.2', '2.3'], 'networks': {'ovirtmgmt': {'iface': 'ovirtmgmt', 'addr': '192.168.5.193', 'cfg': {'PEERROUTES': 'yes', 'IPV6INIT': 'no', 'DEFROUTE': 'yes', 'PEERDNS': 'yes', 'IPV4_FAILURE_FATAL': 'yes', 'DELAY': '40', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'STP': 'no', 'DEVICE': 'ovirtmgmt', 'TYPE': 'bridge', 'ONBOOT': 'yes', 'NAME': 'System eth0'}, 'mtu': '1500', 'netmask': '255.255.255.0', 'stp': 'off', 'bridged': True, 'gateway': '192.168.5.25', 'ports': ['eth0']}}, 'bridges': {'ovirtmgmt': {'addr': '192.168.5.193', 'cfg': {'PEERROUTES': 'yes', 'IPV6INIT': 'no', 'DEFROUTE': 'yes', 'PEERDNS': 'yes', 'IPV4_FAILURE_FATAL': 'yes', 'DELAY': '40', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'STP': 'no', 'DEVICE': 'ovirtmgmt', 'TYPE': 'bridge', 'ONBOOT': 'yes', 'NAME': 'System eth0'}, 'mtu': '1500', 'netmask': '255.255.255.0', 'stp': 'off', 'ports': ['eth0']}}, 'uuid': '4C4C4544-0056-4C10-804A-B7C04F4A4D31_b8:ac:6f:b5:30:51', 'lastClientIface': 'ovirtmgmt', 'nics': {'eth0': {'addr': '', 'cfg': {'HWADDR': 'B8:AC:6F:B5:30:51', 'BRIDGE': 'ovirtmgmt', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'none', 'DEVICE': 'eth0', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': 'b8:ac:6f:b5:30:51', 'speed': 1000}}, 'software_revision': '0.11', 'clusterLevels': ['3.0', '3.1', '3.2'], 'cpuFlags': u'fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,pse36,clflush,dts,acpi,mmx,fxsr,sse,sse2,ss,ht,tm,pbe,syscall,nx,lm,constant_tsc,arch_perfmon,pebs,bts,rep_good,aperfmperf,pni,dtes64,monitor,ds_cpl,vmx,est,tm2,ssse3,cx16,xtpr,pdcm,sse4_1,xsave,lahf_lm,dts,tpr_shadow,vnmi,flexpriority,model_Conroe,model_coreduo,model_core2duo,model_Penryn,model_n270', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:256c354993be', 'netConfigDirty': 'False', 'supportedENGINEs': ['3.0', '3.1'], 'reservedMem': '321', 'bondings': {'bond4': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond0': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}}, 'software_version': '4.10', 'memSize': '3831', 'cpuSpeed': '2926.125', 'cpuSockets': '1', 'vlans': {}, 'cpuCores': '2', 'kvmEnabled': 'true', 'guestOverhead': '65', 'management_ip': '', 'version_name': 'Snow Man', 'emulatedMachines': [u'rhel6.4.0', u'pc', u'rhel6.3.0', u'rhel6.2.0', u'rhel6.1.0', u'rhel6.0.0', u'rhel5.5.0', u'rhel5.4.4', u'rhel5.4.0'], 'operatingSystem': {'release': '4.el6.centos.10', 'version': '6', 'name': 'RHEL'}, 'lastClient': '0.0.0.0'}} Thread-15::DEBUG::2013-03-20 09:37:09,428::BindingXMLRPC::903::vds::(wrapper) client [127.0.0.1]::call getCapabilities with () {} Thread-15::DEBUG::2013-03-20 09:37:09,447::caps::343::root::(_getKeyPackages) rpm package mom not found Thread-15::DEBUG::2013-03-20 09:37:09,448::BindingXMLRPC::910::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:256c354993be'}], 'FC': []}, 'packages2': {'kernel': {'release': '358.2.1.el6.x86_64', 'buildtime': 1363156009.0, 'version': '2.6.32'}, 'spice-server': {'release': '12.el6', 'buildtime': 1361511255L, 'version': '0.12.0'}, 'vdsm': {'release': '0.11.gitee9833b.el6.centos.alt', 'buildtime': 1354579654L, 'version': '4.10.2'}, 'qemu-kvm': {'release': '2.355.0.1.el6.centos.2', 'buildtime': 1363012845L, 'version': '0.12.1.2'}, 'libvirt': {'release': '18.el6', 'buildtime': 1361515221L, 'version': '0.10.2'}, 'qemu-img': {'release': '2.355.0.1.el6.centos.2', 'buildtime': 1363012845L, 'version': '0.12.1.2'}}, 'cpuModel': 'Intel(R) Core(TM)2 Duo CPU E7500 @ 2.93GHz', 'hooks': {}, 'vmTypes': ['kvm'], 'supportedProtocols': ['2.2', '2.3'], 'networks': {'ovirtmgmt': {'iface': 'ovirtmgmt', 'addr': '192.168.5.193', 'cfg': {'PEERROUTES': 'yes', 'IPV6INIT': 'no', 'DEFROUTE': 'yes', 'PEERDNS': 'yes', 'IPV4_FAILURE_FATAL': 'yes', 'DELAY': '40', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'STP': 'no', 'DEVICE': 'ovirtmgmt', 'TYPE': 'bridge', 'ONBOOT': 'yes', 'NAME': 'System eth0'}, 'mtu': '1500', 'netmask': '255.255.255.0', 'stp': 'off', 'bridged': True, 'gateway': '192.168.5.25', 'ports': ['eth0']}}, 'bridges': {'ovirtmgmt': {'addr': '192.168.5.193', 'cfg': {'PEERROUTES': 'yes', 'IPV6INIT': 'no', 'DEFROUTE': 'yes', 'PEERDNS': 'yes', 'IPV4_FAILURE_FATAL': 'yes', 'DELAY': '40', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'STP': 'no', 'DEVICE': 'ovirtmgmt', 'TYPE': 'bridge', 'ONBOOT': 'yes', 'NAME': 'System eth0'}, 'mtu': '1500', 'netmask': '255.255.255.0', 'stp': 'off', 'ports': ['eth0']}}, 'uuid': '4C4C4544-0056-4C10-804A-B7C04F4A4D31_b8:ac:6f:b5:30:51', 'lastClientIface': 'ovirtmgmt', 'nics': {'eth0': {'addr': '', 'cfg': {'HWADDR': 'B8:AC:6F:B5:30:51', 'BRIDGE': 'ovirtmgmt', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'none', 'DEVICE': 'eth0', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': 'b8:ac:6f:b5:30:51', 'speed': 1000}}, 'software_revision': '0.11', 'clusterLevels': ['3.0', '3.1', '3.2'], 'cpuFlags': u'fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,pse36,clflush,dts,acpi,mmx,fxsr,sse,sse2,ss,ht,tm,pbe,syscall,nx,lm,constant_tsc,arch_perfmon,pebs,bts,rep_good,aperfmperf,pni,dtes64,monitor,ds_cpl,vmx,est,tm2,ssse3,cx16,xtpr,pdcm,sse4_1,xsave,lahf_lm,dts,tpr_shadow,vnmi,flexpriority,model_Conroe,model_coreduo,model_core2duo,model_Penryn,model_n270', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:256c354993be', 'netConfigDirty': 'False', 'supportedENGINEs': ['3.0', '3.1'], 'reservedMem': '321', 'bondings': {'bond4': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond0': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}}, 'software_version': '4.10', 'memSize': '3831', 'cpuSpeed': '2926.125', 'cpuSockets': '1', 'vlans': {}, 'cpuCores': '2', 'kvmEnabled': 'true', 'guestOverhead': '65', 'management_ip': '', 'version_name': 'Snow Man', 'emulatedMachines': [u'rhel6.4.0', u'pc', u'rhel6.3.0', u'rhel6.2.0', u'rhel6.1.0', u'rhel6.0.0', u'rhel5.5.0', u'rhel5.4.4', u'rhel5.4.0'], 'operatingSystem': {'release': '4.el6.centos.10', 'version': '6', 'name': 'RHEL'}, 'lastClient': '127.0.0.1'}} Thread-21::DEBUG::2013-03-20 09:37:20,197::task::568::TaskManager.Task::(_updateState) Task=`276d1931-fc66-4a25-b56f-9cc3c1c28879`::moving from state init -> state preparing Thread-21::INFO::2013-03-20 09:37:20,197::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-21::INFO::2013-03-20 09:37:20,197::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} Thread-21::DEBUG::2013-03-20 09:37:20,197::task::1151::TaskManager.Task::(prepare) Task=`276d1931-fc66-4a25-b56f-9cc3c1c28879`::finished: {} Thread-21::DEBUG::2013-03-20 09:37:20,198::task::568::TaskManager.Task::(_updateState) Task=`276d1931-fc66-4a25-b56f-9cc3c1c28879`::moving from state preparing -> state finished Thread-21::DEBUG::2013-03-20 09:37:20,198::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-21::DEBUG::2013-03-20 09:37:20,198::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-21::DEBUG::2013-03-20 09:37:20,198::task::957::TaskManager.Task::(_decref) Task=`276d1931-fc66-4a25-b56f-9cc3c1c28879`::ref 0 aborting False Thread-27::DEBUG::2013-03-20 09:37:30,532::task::568::TaskManager.Task::(_updateState) Task=`70c6c3f0-c90a-4abb-ae74-bfdb3d6b2275`::moving from state init -> state preparing Thread-27::INFO::2013-03-20 09:37:30,532::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-27::INFO::2013-03-20 09:37:30,532::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} Thread-27::DEBUG::2013-03-20 09:37:30,533::task::1151::TaskManager.Task::(prepare) Task=`70c6c3f0-c90a-4abb-ae74-bfdb3d6b2275`::finished: {} Thread-27::DEBUG::2013-03-20 09:37:30,533::task::568::TaskManager.Task::(_updateState) Task=`70c6c3f0-c90a-4abb-ae74-bfdb3d6b2275`::moving from state preparing -> state finished Thread-27::DEBUG::2013-03-20 09:37:30,533::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-27::DEBUG::2013-03-20 09:37:30,533::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-27::DEBUG::2013-03-20 09:37:30,533::task::957::TaskManager.Task::(_decref) Task=`70c6c3f0-c90a-4abb-ae74-bfdb3d6b2275`::ref 0 aborting False MainThread::INFO::2013-03-20 09:37:36,732::vmChannels::135::vds::(stop) VM channels listener was stopped. MainThread::DEBUG::2013-03-20 09:37:36,732::task::568::TaskManager.Task::(_updateState) Task=`f4f7422b-1484-4e85-b4c1-606f06fcae0c`::moving from state init -> state preparing MainThread::INFO::2013-03-20 09:37:36,732::logUtils::37::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None) Thread-11::DEBUG::2013-03-20 09:37:36,733::storageServer::674::ConnectionMonitor::(_monitorConnections) Monitoring stopped MainThread::DEBUG::2013-03-20 09:37:36,810::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks MainThread::INFO::2013-03-20 09:37:36,810::logUtils::39::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None MainThread::DEBUG::2013-03-20 09:37:36,810::task::1151::TaskManager.Task::(prepare) Task=`f4f7422b-1484-4e85-b4c1-606f06fcae0c`::finished: None MainThread::DEBUG::2013-03-20 09:37:36,810::task::568::TaskManager.Task::(_updateState) Task=`f4f7422b-1484-4e85-b4c1-606f06fcae0c`::moving from state preparing -> state finished MainThread::DEBUG::2013-03-20 09:37:36,811::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} MainThread::DEBUG::2013-03-20 09:37:36,811::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} MainThread::DEBUG::2013-03-20 09:37:36,811::task::957::TaskManager.Task::(_decref) Task=`f4f7422b-1484-4e85-b4c1-606f06fcae0c`::ref 0 aborting False MainThread::INFO::2013-03-20 09:37:36,811::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 13 other threads... MainThread::INFO::2013-03-20 09:37:36,811::vdsm::98::vds::(run) <_MainThread(MainThread, started 140160017602304)> MainThread::INFO::2013-03-20 09:37:36,811::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:37:36,811::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:37:36,811::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:37:36,812::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:37:36,812::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:37:36,812::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:37:36,812::vmChannels::135::vds::(stop) VM channels listener was stopped. MainThread::INFO::2013-03-20 09:37:36,812::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:37:36,812::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:37:36,812::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:37:36,812::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:37:36,812::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:37:36,812::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:37:36,813::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:51:41,507::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::DEBUG::2013-03-20 09:51:43,169::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'Storage' MainThread::DEBUG::2013-03-20 09:51:43,170::threadPool::33::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0 MainThread::WARNING::2013-03-20 09:51:43,186::fileUtils::184::fileUtils::(createdir) Dir /rhev/data-center/mnt already exists MainThread::DEBUG::2013-03-20 09:51:43,279::supervdsm::117::SuperVdsmProxy::(_start) Launching Super Vdsm MainThread::DEBUG::2013-03-20 09:51:43,280::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /usr/bin/python /usr/share/vdsm/supervdsmServer.py 8dc00591-0aa6-4655-8a58-90d690999d9e 2220 /var/run/vdsm/svdsm.pid /var/run/vdsm/svdsm.time /var/run/vdsm/svdsm.sock 36' (cwd None) MainThread::DEBUG::2013-03-20 09:51:44,889::supervdsmServer::332::SuperVdsm.Server::(main) Making sure I'm root MainThread::DEBUG::2013-03-20 09:51:44,889::supervdsmServer::336::SuperVdsm.Server::(main) Parsing cmd args MainThread::DEBUG::2013-03-20 09:51:44,889::supervdsmServer::340::SuperVdsm.Server::(main) Creating PID and TIMESTAMP files: /var/run/vdsm/svdsm.pid, /var/run/vdsm/svdsm.time MainThread::DEBUG::2013-03-20 09:51:44,890::supervdsmServer::347::SuperVdsm.Server::(main) Cleaning old socket /var/run/vdsm/svdsm.sock MainThread::DEBUG::2013-03-20 09:51:44,890::supervdsmServer::351::SuperVdsm.Server::(main) Setting up keep alive thread MainThread::DEBUG::2013-03-20 09:51:44,890::supervdsmServer::359::SuperVdsm.Server::(main) Creating remote object manager MainThread::DEBUG::2013-03-20 09:51:44,891::supervdsmServer::371::SuperVdsm.Server::(main) Started serving super vdsm object MainThread::DEBUG::2013-03-20 09:51:45,388::supervdsm::176::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm MainThread::DEBUG::2013-03-20 09:51:45,423::multipath::106::Storage.Multipath::(isEnabled) Current revision of multipath.conf detected, preserving MainThread::DEBUG::2013-03-20 09:51:45,423::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None) MainThread::DEBUG::2013-03-20 09:51:45,561::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 MainThread::DEBUG::2013-03-20 09:51:45,562::hsm::426::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center' MainThread::DEBUG::2013-03-20 09:51:45,567::hsm::458::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt'] MainThread::DEBUG::2013-03-20 09:51:45,567::hsm::459::Storage.HSM::(__cleanStorageRepository) Mount list: [] MainThread::DEBUG::2013-03-20 09:51:45,567::hsm::461::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers MainThread::DEBUG::2013-03-20 09:51:45,568::hsm::504::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center' MainThread::INFO::2013-03-20 09:51:45,569::dispatcher::95::Storage.Dispatcher::(__init__) Starting StorageDispatcher... Thread-12::DEBUG::2013-03-20 09:51:45,569::lvm::334::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:51:45,572::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/lvm pvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,size,vg_name,vg_uuid,pe_start,pe_count,pe_alloc_count,mda_count,dev_size' (cwd None) MainThread::WARNING::2013-03-20 09:51:45,585::clientIF::196::vds::(_prepareMOM) MOM initialization failed and fall back to KsmMonitor MainThread::DEBUG::2013-03-20 09:51:45,586::clientIF::198::vds::(_prepareMOM) Details: Traceback (most recent call last): File "/usr/share/vdsm/clientIF.py", line 194, in _prepareMOM self.mom = MomThread(momconf) File "/usr/share/vdsm/momIF.py", line 34, in __init__ raise Exception("MOM is not available") Exception: MOM is not available MainThread::DEBUG::2013-03-20 09:51:45,639::misc::83::Storage.Misc.excCmd::() '/usr/bin/pgrep -xf ksmd' (cwd None) Thread-12::DEBUG::2013-03-20 09:51:45,721::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 Thread-12::DEBUG::2013-03-20 09:51:45,722::lvm::359::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:51:45,722::lvm::368::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:51:45,722::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free' (cwd None) MainThread::DEBUG::2013-03-20 09:51:45,732::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 MainThread::INFO::2013-03-20 09:51:45,732::ksm::43::vds::(__init__) starting ksm monitor thread, ksm pid is 39 KsmMonitor::DEBUG::2013-03-20 09:51:45,735::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/service ksmtuned start' (cwd None) MainThread::INFO::2013-03-20 09:51:45,743::vmChannels::139::vds::(settimeout) Setting channels' timeout to 30 seconds. VM Channels Listener::INFO::2013-03-20 09:51:45,758::vmChannels::127::vds::(run) Starting VM channels listener thread. MainThread::WARNING::2013-03-20 09:51:45,806::clientIF::182::vds::(_prepareBindings) Unable to load the rest server module. Please make sure it is installed. MainThread::WARNING::2013-03-20 09:51:45,807::clientIF::188::vds::(_prepareBindings) Unable to load the json rpc server module. Please make sure it is installed. KsmMonitor::DEBUG::2013-03-20 09:51:45,850::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 KsmMonitor::DEBUG::2013-03-20 09:51:45,850::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/service ksm start' (cwd None) Thread-12::DEBUG::2013-03-20 09:51:45,886::misc::83::Storage.Misc.excCmd::() SUCCESS: = ' No volume groups found\n'; = 0 Thread-12::DEBUG::2013-03-20 09:51:45,887::lvm::397::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:51:45,887::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,vg_name,attr,size,seg_start_pe,devices,tags' (cwd None) KsmMonitor::DEBUG::2013-03-20 09:51:45,930::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 Thread-12::DEBUG::2013-03-20 09:51:46,030::misc::83::Storage.Misc.excCmd::() SUCCESS: = ' No volume groups found\n'; = 0 Thread-12::DEBUG::2013-03-20 09:51:46,030::misc::1025::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage) Thread-12::DEBUG::2013-03-20 09:51:46,031::misc::1027::SamplingMethod::(__call__) Got in to sampling method Thread-12::DEBUG::2013-03-20 09:51:46,031::misc::1025::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan) Thread-12::DEBUG::2013-03-20 09:51:46,031::misc::1027::SamplingMethod::(__call__) Got in to sampling method Thread-12::DEBUG::2013-03-20 09:51:46,031::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None) Thread-12::DEBUG::2013-03-20 09:51:46,172::misc::83::Storage.Misc.excCmd::() FAILED: = 'iscsiadm: No session found.\n'; = 21 Thread-12::DEBUG::2013-03-20 09:51:46,172::misc::1035::SamplingMethod::(__call__) Returning last result MainProcess|Thread-12::DEBUG::2013-03-20 09:51:46,177::misc::83::Storage.Misc.excCmd::() '/bin/dd of=/sys/class/scsi_host/host0/scan' (cwd None) MainProcess|Thread-12::DEBUG::2013-03-20 09:51:46,182::misc::83::Storage.Misc.excCmd::() '/bin/dd of=/sys/class/scsi_host/host1/scan' (cwd None) MainProcess|Thread-12::DEBUG::2013-03-20 09:51:46,185::iscsi::388::Storage.ISCSI::(forceIScsiScan) Performing SCSI scan, this will take up to 30 seconds Thread-12::DEBUG::2013-03-20 09:51:48,190::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/multipath' (cwd None) Thread-12::DEBUG::2013-03-20 09:51:48,364::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 Thread-12::DEBUG::2013-03-20 09:51:48,364::lvm::477::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:51:48,364::lvm::479::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:51:48,365::lvm::488::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:51:48,365::lvm::490::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:51:48,365::lvm::508::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:51:48,365::lvm::510::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:51:48,366::misc::1035::SamplingMethod::(__call__) Returning last result Thread-12::WARNING::2013-03-20 09:51:48,366::fileUtils::184::fileUtils::(createdir) Dir /rhev/data-center/hsm-tasks already exists Thread-14::DEBUG::2013-03-20 09:52:00,033::BindingXMLRPC::903::vds::(wrapper) client [127.0.0.1]::call getCapabilities with () {} Thread-14::DEBUG::2013-03-20 09:52:00,351::caps::343::root::(_getKeyPackages) rpm package mom not found Thread-14::DEBUG::2013-03-20 09:52:00,360::BindingXMLRPC::910::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:256c354993be'}], 'FC': []}, 'packages2': {'kernel': {'release': '358.2.1.el6.x86_64', 'buildtime': 1363156009.0, 'version': '2.6.32'}, 'spice-server': {'release': '12.el6', 'buildtime': 1361511255L, 'version': '0.12.0'}, 'vdsm': {'release': '0.11.gitee9833b.el6.centos.alt', 'buildtime': 1354579654L, 'version': '4.10.2'}, 'qemu-kvm': {'release': '2.355.0.1.el6.centos.2', 'buildtime': 1363012845L, 'version': '0.12.1.2'}, 'libvirt': {'release': '18.el6', 'buildtime': 1361515221L, 'version': '0.10.2'}, 'qemu-img': {'release': '2.355.0.1.el6.centos.2', 'buildtime': 1363012845L, 'version': '0.12.1.2'}}, 'cpuModel': 'Intel(R) Core(TM)2 Duo CPU E7500 @ 2.93GHz', 'hooks': {}, 'vmTypes': ['kvm'], 'supportedProtocols': ['2.2', '2.3'], 'networks': {'ovirtmgmt': {'iface': 'ovirtmgmt', 'addr': '192.168.5.193', 'cfg': {'PEERROUTES': 'yes', 'IPV6INIT': 'no', 'DEFROUTE': 'yes', 'PEERDNS': 'yes', 'IPV4_FAILURE_FATAL': 'yes', 'DELAY': '40', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'STP': 'no', 'DEVICE': 'ovirtmgmt', 'TYPE': 'bridge', 'ONBOOT': 'yes', 'NAME': 'System eth0'}, 'mtu': '1500', 'netmask': '255.255.255.0', 'stp': 'off', 'bridged': True, 'gateway': '192.168.5.25', 'ports': ['eth0']}}, 'bridges': {'ovirtmgmt': {'addr': '192.168.5.193', 'cfg': {'PEERROUTES': 'yes', 'IPV6INIT': 'no', 'DEFROUTE': 'yes', 'PEERDNS': 'yes', 'IPV4_FAILURE_FATAL': 'yes', 'DELAY': '40', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'STP': 'no', 'DEVICE': 'ovirtmgmt', 'TYPE': 'bridge', 'ONBOOT': 'yes', 'NAME': 'System eth0'}, 'mtu': '1500', 'netmask': '255.255.255.0', 'stp': 'off', 'ports': ['eth0']}}, 'uuid': '4C4C4544-0056-4C10-804A-B7C04F4A4D31_b8:ac:6f:b5:30:51', 'lastClientIface': 'ovirtmgmt', 'nics': {'eth0': {'addr': '', 'cfg': {'HWADDR': 'B8:AC:6F:B5:30:51', 'BRIDGE': 'ovirtmgmt', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'none', 'DEVICE': 'eth0', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': 'b8:ac:6f:b5:30:51', 'speed': 1000}}, 'software_revision': '0.11', 'clusterLevels': ['3.0', '3.1', '3.2'], 'cpuFlags': u'fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,pse36,clflush,dts,acpi,mmx,fxsr,sse,sse2,ss,ht,tm,pbe,syscall,nx,lm,constant_tsc,arch_perfmon,pebs,bts,rep_good,aperfmperf,pni,dtes64,monitor,ds_cpl,vmx,est,tm2,ssse3,cx16,xtpr,pdcm,sse4_1,xsave,lahf_lm,dts,tpr_shadow,vnmi,flexpriority,model_Conroe,model_coreduo,model_core2duo,model_Penryn,model_n270', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:256c354993be', 'netConfigDirty': 'False', 'supportedENGINEs': ['3.0', '3.1'], 'reservedMem': '321', 'bondings': {'bond4': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond0': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}}, 'software_version': '4.10', 'memSize': '3831', 'cpuSpeed': '2926.054', 'cpuSockets': '1', 'vlans': {}, 'cpuCores': '2', 'kvmEnabled': 'true', 'guestOverhead': '65', 'management_ip': '', 'version_name': 'Snow Man', 'emulatedMachines': [u'rhel6.4.0', u'pc', u'rhel6.3.0', u'rhel6.2.0', u'rhel6.1.0', u'rhel6.0.0', u'rhel5.5.0', u'rhel5.4.4', u'rhel5.4.0'], 'operatingSystem': {'release': '4.el6.centos.10', 'version': '6', 'name': 'RHEL'}, 'lastClient': '0.0.0.0'}} Thread-15::DEBUG::2013-03-20 09:52:00,577::BindingXMLRPC::903::vds::(wrapper) client [127.0.0.1]::call getCapabilities with () {} Thread-15::DEBUG::2013-03-20 09:52:00,593::caps::343::root::(_getKeyPackages) rpm package mom not found Thread-15::DEBUG::2013-03-20 09:52:00,594::BindingXMLRPC::910::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:256c354993be'}], 'FC': []}, 'packages2': {'kernel': {'release': '358.2.1.el6.x86_64', 'buildtime': 1363156009.0, 'version': '2.6.32'}, 'spice-server': {'release': '12.el6', 'buildtime': 1361511255L, 'version': '0.12.0'}, 'vdsm': {'release': '0.11.gitee9833b.el6.centos.alt', 'buildtime': 1354579654L, 'version': '4.10.2'}, 'qemu-kvm': {'release': '2.355.0.1.el6.centos.2', 'buildtime': 1363012845L, 'version': '0.12.1.2'}, 'libvirt': {'release': '18.el6', 'buildtime': 1361515221L, 'version': '0.10.2'}, 'qemu-img': {'release': '2.355.0.1.el6.centos.2', 'buildtime': 1363012845L, 'version': '0.12.1.2'}}, 'cpuModel': 'Intel(R) Core(TM)2 Duo CPU E7500 @ 2.93GHz', 'hooks': {}, 'vmTypes': ['kvm'], 'supportedProtocols': ['2.2', '2.3'], 'networks': {'ovirtmgmt': {'iface': 'ovirtmgmt', 'addr': '192.168.5.193', 'cfg': {'PEERROUTES': 'yes', 'IPV6INIT': 'no', 'DEFROUTE': 'yes', 'PEERDNS': 'yes', 'IPV4_FAILURE_FATAL': 'yes', 'DELAY': '40', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'STP': 'no', 'DEVICE': 'ovirtmgmt', 'TYPE': 'bridge', 'ONBOOT': 'yes', 'NAME': 'System eth0'}, 'mtu': '1500', 'netmask': '255.255.255.0', 'stp': 'off', 'bridged': True, 'gateway': '192.168.5.25', 'ports': ['eth0']}}, 'bridges': {'ovirtmgmt': {'addr': '192.168.5.193', 'cfg': {'PEERROUTES': 'yes', 'IPV6INIT': 'no', 'DEFROUTE': 'yes', 'PEERDNS': 'yes', 'IPV4_FAILURE_FATAL': 'yes', 'DELAY': '40', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'STP': 'no', 'DEVICE': 'ovirtmgmt', 'TYPE': 'bridge', 'ONBOOT': 'yes', 'NAME': 'System eth0'}, 'mtu': '1500', 'netmask': '255.255.255.0', 'stp': 'off', 'ports': ['eth0']}}, 'uuid': '4C4C4544-0056-4C10-804A-B7C04F4A4D31_b8:ac:6f:b5:30:51', 'lastClientIface': 'ovirtmgmt', 'nics': {'eth0': {'addr': '', 'cfg': {'HWADDR': 'B8:AC:6F:B5:30:51', 'BRIDGE': 'ovirtmgmt', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'none', 'DEVICE': 'eth0', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': 'b8:ac:6f:b5:30:51', 'speed': 1000}}, 'software_revision': '0.11', 'clusterLevels': ['3.0', '3.1', '3.2'], 'cpuFlags': u'fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,pse36,clflush,dts,acpi,mmx,fxsr,sse,sse2,ss,ht,tm,pbe,syscall,nx,lm,constant_tsc,arch_perfmon,pebs,bts,rep_good,aperfmperf,pni,dtes64,monitor,ds_cpl,vmx,est,tm2,ssse3,cx16,xtpr,pdcm,sse4_1,xsave,lahf_lm,dts,tpr_shadow,vnmi,flexpriority,model_Conroe,model_coreduo,model_core2duo,model_Penryn,model_n270', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:256c354993be', 'netConfigDirty': 'False', 'supportedENGINEs': ['3.0', '3.1'], 'reservedMem': '321', 'bondings': {'bond4': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond0': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}}, 'software_version': '4.10', 'memSize': '3831', 'cpuSpeed': '2926.054', 'cpuSockets': '1', 'vlans': {}, 'cpuCores': '2', 'kvmEnabled': 'true', 'guestOverhead': '65', 'management_ip': '', 'version_name': 'Snow Man', 'emulatedMachines': [u'rhel6.4.0', u'pc', u'rhel6.3.0', u'rhel6.2.0', u'rhel6.1.0', u'rhel6.0.0', u'rhel5.5.0', u'rhel5.4.4', u'rhel5.4.0'], 'operatingSystem': {'release': '4.el6.centos.10', 'version': '6', 'name': 'RHEL'}, 'lastClient': '127.0.0.1'}} MainThread::INFO::2013-03-20 09:52:09,282::vmChannels::135::vds::(stop) VM channels listener was stopped. MainThread::DEBUG::2013-03-20 09:52:09,288::task::568::TaskManager.Task::(_updateState) Task=`f69298ae-9ebd-4942-aca0-fb4c8180aada`::moving from state init -> state preparing MainThread::INFO::2013-03-20 09:52:09,288::logUtils::37::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None) Thread-11::DEBUG::2013-03-20 09:52:09,289::storageServer::674::ConnectionMonitor::(_monitorConnections) Monitoring stopped MainThread::DEBUG::2013-03-20 09:52:09,362::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks MainThread::INFO::2013-03-20 09:52:09,362::logUtils::39::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None MainThread::DEBUG::2013-03-20 09:52:09,362::task::1151::TaskManager.Task::(prepare) Task=`f69298ae-9ebd-4942-aca0-fb4c8180aada`::finished: None MainThread::DEBUG::2013-03-20 09:52:09,362::task::568::TaskManager.Task::(_updateState) Task=`f69298ae-9ebd-4942-aca0-fb4c8180aada`::moving from state preparing -> state finished MainThread::DEBUG::2013-03-20 09:52:09,362::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} MainThread::DEBUG::2013-03-20 09:52:09,362::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} MainThread::DEBUG::2013-03-20 09:52:09,362::task::957::TaskManager.Task::(_decref) Task=`f69298ae-9ebd-4942-aca0-fb4c8180aada`::ref 0 aborting False MainThread::INFO::2013-03-20 09:52:09,363::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 13 other threads... MainThread::INFO::2013-03-20 09:52:09,363::vdsm::98::vds::(run) <_MainThread(MainThread, started 140104273733376)> MainThread::INFO::2013-03-20 09:52:09,363::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:52:09,363::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:52:09,363::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:52:09,363::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:52:09,363::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:52:09,363::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:52:09,363::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:52:09,364::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:52:09,364::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:52:09,364::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:52:09,364::vmChannels::135::vds::(stop) VM channels listener was stopped. MainThread::INFO::2013-03-20 09:52:09,364::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:52:09,364::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:52:09,364::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:53:14,430::vdsm::88::vds::(run) I am the actual vdsm 4.10-0.11 localhost.localdomain (2.6.32-358.2.1.el6.x86_64) MainThread::DEBUG::2013-03-20 09:53:16,688::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'Storage' MainThread::DEBUG::2013-03-20 09:53:16,688::threadPool::33::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0 MainThread::WARNING::2013-03-20 09:53:16,709::fileUtils::184::fileUtils::(createdir) Dir /rhev/data-center/mnt already exists MainThread::DEBUG::2013-03-20 09:53:16,808::supervdsm::117::SuperVdsmProxy::(_start) Launching Super Vdsm MainThread::DEBUG::2013-03-20 09:53:16,813::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /usr/bin/python /usr/share/vdsm/supervdsmServer.py 380da2cd-94bd-437f-9cae-85b7239fd69f 2242 /var/run/vdsm/svdsm.pid /var/run/vdsm/svdsm.time /var/run/vdsm/svdsm.sock 36' (cwd None) MainThread::DEBUG::2013-03-20 09:53:17,874::supervdsmServer::332::SuperVdsm.Server::(main) Making sure I'm root MainThread::DEBUG::2013-03-20 09:53:17,874::supervdsmServer::336::SuperVdsm.Server::(main) Parsing cmd args MainThread::DEBUG::2013-03-20 09:53:17,874::supervdsmServer::340::SuperVdsm.Server::(main) Creating PID and TIMESTAMP files: /var/run/vdsm/svdsm.pid, /var/run/vdsm/svdsm.time MainThread::DEBUG::2013-03-20 09:53:17,875::supervdsmServer::347::SuperVdsm.Server::(main) Cleaning old socket /var/run/vdsm/svdsm.sock MainThread::DEBUG::2013-03-20 09:53:17,875::supervdsmServer::351::SuperVdsm.Server::(main) Setting up keep alive thread MainThread::DEBUG::2013-03-20 09:53:17,875::supervdsmServer::359::SuperVdsm.Server::(main) Creating remote object manager MainThread::DEBUG::2013-03-20 09:53:17,877::supervdsmServer::371::SuperVdsm.Server::(main) Started serving super vdsm object MainThread::DEBUG::2013-03-20 09:53:18,853::supervdsm::176::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm MainThread::DEBUG::2013-03-20 09:53:18,867::multipath::106::Storage.Multipath::(isEnabled) Current revision of multipath.conf detected, preserving MainThread::DEBUG::2013-03-20 09:53:18,867::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None) MainThread::DEBUG::2013-03-20 09:53:19,007::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 MainThread::DEBUG::2013-03-20 09:53:19,008::hsm::426::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center' MainThread::DEBUG::2013-03-20 09:53:19,011::hsm::458::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt'] MainThread::DEBUG::2013-03-20 09:53:19,012::hsm::459::Storage.HSM::(__cleanStorageRepository) Mount list: [] MainThread::DEBUG::2013-03-20 09:53:19,012::hsm::461::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers MainThread::DEBUG::2013-03-20 09:53:19,012::hsm::504::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center' MainThread::INFO::2013-03-20 09:53:19,017::dispatcher::95::Storage.Dispatcher::(__init__) Starting StorageDispatcher... Thread-12::DEBUG::2013-03-20 09:53:19,020::lvm::334::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:53:19,021::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/lvm pvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,size,vg_name,vg_uuid,pe_start,pe_count,pe_alloc_count,mda_count,dev_size' (cwd None) MainThread::WARNING::2013-03-20 09:53:19,043::clientIF::196::vds::(_prepareMOM) MOM initialization failed and fall back to KsmMonitor MainThread::DEBUG::2013-03-20 09:53:19,044::clientIF::198::vds::(_prepareMOM) Details: Traceback (most recent call last): File "/usr/share/vdsm/clientIF.py", line 194, in _prepareMOM self.mom = MomThread(momconf) File "/usr/share/vdsm/momIF.py", line 34, in __init__ raise Exception("MOM is not available") Exception: MOM is not available Thread-12::DEBUG::2013-03-20 09:53:19,157::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 MainThread::DEBUG::2013-03-20 09:53:19,203::misc::83::Storage.Misc.excCmd::() '/usr/bin/pgrep -xf ksmd' (cwd None) Thread-12::DEBUG::2013-03-20 09:53:19,203::lvm::359::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:53:19,233::lvm::368::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:53:19,233::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free' (cwd None) MainThread::DEBUG::2013-03-20 09:53:19,265::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 MainThread::INFO::2013-03-20 09:53:19,266::ksm::43::vds::(__init__) starting ksm monitor thread, ksm pid is 39 KsmMonitor::DEBUG::2013-03-20 09:53:19,270::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/service ksmtuned start' (cwd None) MainThread::INFO::2013-03-20 09:53:19,288::vmChannels::139::vds::(settimeout) Setting channels' timeout to 30 seconds. VM Channels Listener::INFO::2013-03-20 09:53:19,291::vmChannels::127::vds::(run) Starting VM channels listener thread. Thread-12::DEBUG::2013-03-20 09:53:19,446::misc::83::Storage.Misc.excCmd::() SUCCESS: = ' No volume groups found\n'; = 0 MainThread::WARNING::2013-03-20 09:53:19,447::clientIF::182::vds::(_prepareBindings) Unable to load the rest server module. Please make sure it is installed. MainThread::WARNING::2013-03-20 09:53:19,460::clientIF::188::vds::(_prepareBindings) Unable to load the json rpc server module. Please make sure it is installed. KsmMonitor::DEBUG::2013-03-20 09:53:19,447::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 Thread-12::DEBUG::2013-03-20 09:53:19,460::lvm::397::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:53:19,461::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,vg_name,attr,size,seg_start_pe,devices,tags' (cwd None) KsmMonitor::DEBUG::2013-03-20 09:53:19,461::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/service ksm start' (cwd None) KsmMonitor::DEBUG::2013-03-20 09:53:19,544::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 Thread-12::DEBUG::2013-03-20 09:53:19,620::misc::83::Storage.Misc.excCmd::() SUCCESS: = ' No volume groups found\n'; = 0 Thread-12::DEBUG::2013-03-20 09:53:19,620::misc::1025::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage) Thread-12::DEBUG::2013-03-20 09:53:19,620::misc::1027::SamplingMethod::(__call__) Got in to sampling method Thread-12::DEBUG::2013-03-20 09:53:19,620::misc::1025::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan) Thread-12::DEBUG::2013-03-20 09:53:19,621::misc::1027::SamplingMethod::(__call__) Got in to sampling method Thread-12::DEBUG::2013-03-20 09:53:19,621::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None) Thread-12::DEBUG::2013-03-20 09:53:19,812::misc::83::Storage.Misc.excCmd::() FAILED: = 'iscsiadm: No session found.\n'; = 21 Thread-12::DEBUG::2013-03-20 09:53:19,812::misc::1035::SamplingMethod::(__call__) Returning last result MainProcess|Thread-12::DEBUG::2013-03-20 09:53:19,814::misc::83::Storage.Misc.excCmd::() '/bin/dd of=/sys/class/scsi_host/host0/scan' (cwd None) MainProcess|Thread-12::DEBUG::2013-03-20 09:53:19,816::misc::83::Storage.Misc.excCmd::() '/bin/dd of=/sys/class/scsi_host/host1/scan' (cwd None) MainProcess|Thread-12::DEBUG::2013-03-20 09:53:19,818::iscsi::388::Storage.ISCSI::(forceIScsiScan) Performing SCSI scan, this will take up to 30 seconds Thread-12::DEBUG::2013-03-20 09:53:21,823::misc::83::Storage.Misc.excCmd::() '/usr/bin/sudo -n /sbin/multipath' (cwd None) Thread-12::DEBUG::2013-03-20 09:53:22,027::misc::83::Storage.Misc.excCmd::() SUCCESS: = ''; = 0 Thread-12::DEBUG::2013-03-20 09:53:22,027::lvm::477::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:53:22,027::lvm::479::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:53:22,028::lvm::488::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:53:22,028::lvm::490::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:53:22,028::lvm::508::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex Thread-12::DEBUG::2013-03-20 09:53:22,028::lvm::510::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex Thread-12::DEBUG::2013-03-20 09:53:22,028::misc::1035::SamplingMethod::(__call__) Returning last result Thread-12::WARNING::2013-03-20 09:53:22,029::fileUtils::184::fileUtils::(createdir) Dir /rhev/data-center/hsm-tasks already exists Thread-14::DEBUG::2013-03-20 09:53:32,293::BindingXMLRPC::903::vds::(wrapper) client [127.0.0.1]::call getCapabilities with () {} Thread-14::DEBUG::2013-03-20 09:53:32,609::caps::343::root::(_getKeyPackages) rpm package mom not found Thread-14::DEBUG::2013-03-20 09:53:32,618::BindingXMLRPC::910::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:256c354993be'}], 'FC': []}, 'packages2': {'kernel': {'release': '358.2.1.el6.x86_64', 'buildtime': 1363156009.0, 'version': '2.6.32'}, 'spice-server': {'release': '12.el6', 'buildtime': 1361511255L, 'version': '0.12.0'}, 'vdsm': {'release': '0.11.gitee9833b.el6.centos.alt', 'buildtime': 1354579654L, 'version': '4.10.2'}, 'qemu-kvm': {'release': '2.355.0.1.el6.centos.2', 'buildtime': 1363012845L, 'version': '0.12.1.2'}, 'libvirt': {'release': '18.el6', 'buildtime': 1361515221L, 'version': '0.10.2'}, 'qemu-img': {'release': '2.355.0.1.el6.centos.2', 'buildtime': 1363012845L, 'version': '0.12.1.2'}}, 'cpuModel': 'Intel(R) Core(TM)2 Duo CPU E7500 @ 2.93GHz', 'hooks': {}, 'vmTypes': ['kvm'], 'supportedProtocols': ['2.2', '2.3'], 'networks': {'ovirtmgmt': {'iface': 'ovirtmgmt', 'addr': '192.168.5.193', 'cfg': {'PEERROUTES': 'yes', 'IPV6INIT': 'no', 'DEFROUTE': 'yes', 'PEERDNS': 'yes', 'IPV4_FAILURE_FATAL': 'yes', 'DELAY': '40', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'STP': 'no', 'DEVICE': 'ovirtmgmt', 'TYPE': 'bridge', 'ONBOOT': 'yes', 'NAME': 'System eth0'}, 'mtu': '1500', 'netmask': '255.255.255.0', 'stp': 'off', 'bridged': True, 'gateway': '192.168.5.25', 'ports': ['eth0']}}, 'bridges': {'ovirtmgmt': {'addr': '192.168.5.193', 'cfg': {'PEERROUTES': 'yes', 'IPV6INIT': 'no', 'DEFROUTE': 'yes', 'PEERDNS': 'yes', 'IPV4_FAILURE_FATAL': 'yes', 'DELAY': '40', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'STP': 'no', 'DEVICE': 'ovirtmgmt', 'TYPE': 'bridge', 'ONBOOT': 'yes', 'NAME': 'System eth0'}, 'mtu': '1500', 'netmask': '255.255.255.0', 'stp': 'off', 'ports': ['eth0']}}, 'uuid': '4C4C4544-0056-4C10-804A-B7C04F4A4D31_b8:ac:6f:b5:30:51', 'lastClientIface': 'ovirtmgmt', 'nics': {'eth0': {'addr': '', 'cfg': {'HWADDR': 'B8:AC:6F:B5:30:51', 'BRIDGE': 'ovirtmgmt', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'none', 'DEVICE': 'eth0', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': 'b8:ac:6f:b5:30:51', 'speed': 1000}}, 'software_revision': '0.11', 'clusterLevels': ['3.0', '3.1', '3.2'], 'cpuFlags': u'fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,pse36,clflush,dts,acpi,mmx,fxsr,sse,sse2,ss,ht,tm,pbe,syscall,nx,lm,constant_tsc,arch_perfmon,pebs,bts,rep_good,aperfmperf,pni,dtes64,monitor,ds_cpl,vmx,est,tm2,ssse3,cx16,xtpr,pdcm,sse4_1,xsave,lahf_lm,dts,tpr_shadow,vnmi,flexpriority,model_Conroe,model_coreduo,model_core2duo,model_Penryn,model_n270', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:256c354993be', 'netConfigDirty': 'False', 'supportedENGINEs': ['3.0', '3.1'], 'reservedMem': '321', 'bondings': {'bond4': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond0': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}}, 'software_version': '4.10', 'memSize': '3831', 'cpuSpeed': '2926.167', 'cpuSockets': '1', 'vlans': {}, 'cpuCores': '2', 'kvmEnabled': 'true', 'guestOverhead': '65', 'management_ip': '', 'version_name': 'Snow Man', 'emulatedMachines': [u'rhel6.4.0', u'pc', u'rhel6.3.0', u'rhel6.2.0', u'rhel6.1.0', u'rhel6.0.0', u'rhel5.5.0', u'rhel5.4.4', u'rhel5.4.0'], 'operatingSystem': {'release': '4.el6.centos.10', 'version': '6', 'name': 'RHEL'}, 'lastClient': '0.0.0.0'}} Thread-15::DEBUG::2013-03-20 09:53:32,831::BindingXMLRPC::903::vds::(wrapper) client [127.0.0.1]::call getCapabilities with () {} Thread-15::DEBUG::2013-03-20 09:53:32,848::caps::343::root::(_getKeyPackages) rpm package mom not found Thread-15::DEBUG::2013-03-20 09:53:32,848::BindingXMLRPC::910::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:256c354993be'}], 'FC': []}, 'packages2': {'kernel': {'release': '358.2.1.el6.x86_64', 'buildtime': 1363156009.0, 'version': '2.6.32'}, 'spice-server': {'release': '12.el6', 'buildtime': 1361511255L, 'version': '0.12.0'}, 'vdsm': {'release': '0.11.gitee9833b.el6.centos.alt', 'buildtime': 1354579654L, 'version': '4.10.2'}, 'qemu-kvm': {'release': '2.355.0.1.el6.centos.2', 'buildtime': 1363012845L, 'version': '0.12.1.2'}, 'libvirt': {'release': '18.el6', 'buildtime': 1361515221L, 'version': '0.10.2'}, 'qemu-img': {'release': '2.355.0.1.el6.centos.2', 'buildtime': 1363012845L, 'version': '0.12.1.2'}}, 'cpuModel': 'Intel(R) Core(TM)2 Duo CPU E7500 @ 2.93GHz', 'hooks': {}, 'vmTypes': ['kvm'], 'supportedProtocols': ['2.2', '2.3'], 'networks': {'ovirtmgmt': {'iface': 'ovirtmgmt', 'addr': '192.168.5.193', 'cfg': {'PEERROUTES': 'yes', 'IPV6INIT': 'no', 'DEFROUTE': 'yes', 'PEERDNS': 'yes', 'IPV4_FAILURE_FATAL': 'yes', 'DELAY': '40', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'STP': 'no', 'DEVICE': 'ovirtmgmt', 'TYPE': 'bridge', 'ONBOOT': 'yes', 'NAME': 'System eth0'}, 'mtu': '1500', 'netmask': '255.255.255.0', 'stp': 'off', 'bridged': True, 'gateway': '192.168.5.25', 'ports': ['eth0']}}, 'bridges': {'ovirtmgmt': {'addr': '192.168.5.193', 'cfg': {'PEERROUTES': 'yes', 'IPV6INIT': 'no', 'DEFROUTE': 'yes', 'PEERDNS': 'yes', 'IPV4_FAILURE_FATAL': 'yes', 'DELAY': '40', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'STP': 'no', 'DEVICE': 'ovirtmgmt', 'TYPE': 'bridge', 'ONBOOT': 'yes', 'NAME': 'System eth0'}, 'mtu': '1500', 'netmask': '255.255.255.0', 'stp': 'off', 'ports': ['eth0']}}, 'uuid': '4C4C4544-0056-4C10-804A-B7C04F4A4D31_b8:ac:6f:b5:30:51', 'lastClientIface': 'ovirtmgmt', 'nics': {'eth0': {'addr': '', 'cfg': {'HWADDR': 'B8:AC:6F:B5:30:51', 'BRIDGE': 'ovirtmgmt', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'none', 'DEVICE': 'eth0', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': 'b8:ac:6f:b5:30:51', 'speed': 1000}}, 'software_revision': '0.11', 'clusterLevels': ['3.0', '3.1', '3.2'], 'cpuFlags': u'fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,pse36,clflush,dts,acpi,mmx,fxsr,sse,sse2,ss,ht,tm,pbe,syscall,nx,lm,constant_tsc,arch_perfmon,pebs,bts,rep_good,aperfmperf,pni,dtes64,monitor,ds_cpl,vmx,est,tm2,ssse3,cx16,xtpr,pdcm,sse4_1,xsave,lahf_lm,dts,tpr_shadow,vnmi,flexpriority,model_Conroe,model_coreduo,model_core2duo,model_Penryn,model_n270', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:256c354993be', 'netConfigDirty': 'False', 'supportedENGINEs': ['3.0', '3.1'], 'reservedMem': '321', 'bondings': {'bond4': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond0': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}}, 'software_version': '4.10', 'memSize': '3831', 'cpuSpeed': '2926.167', 'cpuSockets': '1', 'vlans': {}, 'cpuCores': '2', 'kvmEnabled': 'true', 'guestOverhead': '65', 'management_ip': '', 'version_name': 'Snow Man', 'emulatedMachines': [u'rhel6.4.0', u'pc', u'rhel6.3.0', u'rhel6.2.0', u'rhel6.1.0', u'rhel6.0.0', u'rhel5.5.0', u'rhel5.4.4', u'rhel5.4.0'], 'operatingSystem': {'release': '4.el6.centos.10', 'version': '6', 'name': 'RHEL'}, 'lastClient': '127.0.0.1'}} Thread-21::DEBUG::2013-03-20 09:53:43,618::task::568::TaskManager.Task::(_updateState) Task=`e362177c-1297-407b-9d2a-2f894c9c9fbf`::moving from state init -> state preparing Thread-21::INFO::2013-03-20 09:53:43,619::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-21::INFO::2013-03-20 09:53:43,619::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} Thread-21::DEBUG::2013-03-20 09:53:43,619::task::1151::TaskManager.Task::(prepare) Task=`e362177c-1297-407b-9d2a-2f894c9c9fbf`::finished: {} Thread-21::DEBUG::2013-03-20 09:53:43,619::task::568::TaskManager.Task::(_updateState) Task=`e362177c-1297-407b-9d2a-2f894c9c9fbf`::moving from state preparing -> state finished Thread-21::DEBUG::2013-03-20 09:53:43,619::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-21::DEBUG::2013-03-20 09:53:43,619::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-21::DEBUG::2013-03-20 09:53:43,619::task::957::TaskManager.Task::(_decref) Task=`e362177c-1297-407b-9d2a-2f894c9c9fbf`::ref 0 aborting False Thread-27::DEBUG::2013-03-20 09:53:53,954::task::568::TaskManager.Task::(_updateState) Task=`1fd5a896-454b-44d1-a71f-ff201687ce3a`::moving from state init -> state preparing Thread-27::INFO::2013-03-20 09:53:53,954::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-27::INFO::2013-03-20 09:53:53,954::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} Thread-27::DEBUG::2013-03-20 09:53:53,954::task::1151::TaskManager.Task::(prepare) Task=`1fd5a896-454b-44d1-a71f-ff201687ce3a`::finished: {} Thread-27::DEBUG::2013-03-20 09:53:53,954::task::568::TaskManager.Task::(_updateState) Task=`1fd5a896-454b-44d1-a71f-ff201687ce3a`::moving from state preparing -> state finished Thread-27::DEBUG::2013-03-20 09:53:53,954::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-27::DEBUG::2013-03-20 09:53:53,955::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-27::DEBUG::2013-03-20 09:53:53,955::task::957::TaskManager.Task::(_decref) Task=`1fd5a896-454b-44d1-a71f-ff201687ce3a`::ref 0 aborting False Thread-33::DEBUG::2013-03-20 09:54:04,287::task::568::TaskManager.Task::(_updateState) Task=`5479376e-d5f5-4ee6-a898-16c64d803e1e`::moving from state init -> state preparing Thread-33::INFO::2013-03-20 09:54:04,287::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-33::INFO::2013-03-20 09:54:04,287::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} Thread-33::DEBUG::2013-03-20 09:54:04,288::task::1151::TaskManager.Task::(prepare) Task=`5479376e-d5f5-4ee6-a898-16c64d803e1e`::finished: {} Thread-33::DEBUG::2013-03-20 09:54:04,288::task::568::TaskManager.Task::(_updateState) Task=`5479376e-d5f5-4ee6-a898-16c64d803e1e`::moving from state preparing -> state finished Thread-33::DEBUG::2013-03-20 09:54:04,288::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-33::DEBUG::2013-03-20 09:54:04,288::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-33::DEBUG::2013-03-20 09:54:04,288::task::957::TaskManager.Task::(_decref) Task=`5479376e-d5f5-4ee6-a898-16c64d803e1e`::ref 0 aborting False Thread-39::DEBUG::2013-03-20 09:54:14,625::task::568::TaskManager.Task::(_updateState) Task=`12c4b98d-26ce-4888-93a7-f4967d410620`::moving from state init -> state preparing Thread-39::INFO::2013-03-20 09:54:14,626::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-39::INFO::2013-03-20 09:54:14,626::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} Thread-39::DEBUG::2013-03-20 09:54:14,626::task::1151::TaskManager.Task::(prepare) Task=`12c4b98d-26ce-4888-93a7-f4967d410620`::finished: {} Thread-39::DEBUG::2013-03-20 09:54:14,626::task::568::TaskManager.Task::(_updateState) Task=`12c4b98d-26ce-4888-93a7-f4967d410620`::moving from state preparing -> state finished Thread-39::DEBUG::2013-03-20 09:54:14,626::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-39::DEBUG::2013-03-20 09:54:14,626::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-39::DEBUG::2013-03-20 09:54:14,626::task::957::TaskManager.Task::(_decref) Task=`12c4b98d-26ce-4888-93a7-f4967d410620`::ref 0 aborting False Thread-45::DEBUG::2013-03-20 09:54:24,954::task::568::TaskManager.Task::(_updateState) Task=`0735eeab-f50b-484d-b78f-9d179a5108bf`::moving from state init -> state preparing Thread-45::INFO::2013-03-20 09:54:24,954::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-45::INFO::2013-03-20 09:54:24,954::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} Thread-45::DEBUG::2013-03-20 09:54:24,954::task::1151::TaskManager.Task::(prepare) Task=`0735eeab-f50b-484d-b78f-9d179a5108bf`::finished: {} Thread-45::DEBUG::2013-03-20 09:54:24,954::task::568::TaskManager.Task::(_updateState) Task=`0735eeab-f50b-484d-b78f-9d179a5108bf`::moving from state preparing -> state finished Thread-45::DEBUG::2013-03-20 09:54:24,954::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-45::DEBUG::2013-03-20 09:54:24,954::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-45::DEBUG::2013-03-20 09:54:24,955::task::957::TaskManager.Task::(_decref) Task=`0735eeab-f50b-484d-b78f-9d179a5108bf`::ref 0 aborting False Thread-51::DEBUG::2013-03-20 09:54:35,281::task::568::TaskManager.Task::(_updateState) Task=`fa8e34a1-a011-4a0b-bd9e-403f43e14eeb`::moving from state init -> state preparing Thread-51::INFO::2013-03-20 09:54:35,282::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-51::INFO::2013-03-20 09:54:35,282::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} Thread-51::DEBUG::2013-03-20 09:54:35,282::task::1151::TaskManager.Task::(prepare) Task=`fa8e34a1-a011-4a0b-bd9e-403f43e14eeb`::finished: {} Thread-51::DEBUG::2013-03-20 09:54:35,282::task::568::TaskManager.Task::(_updateState) Task=`fa8e34a1-a011-4a0b-bd9e-403f43e14eeb`::moving from state preparing -> state finished Thread-51::DEBUG::2013-03-20 09:54:35,282::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-51::DEBUG::2013-03-20 09:54:35,282::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-51::DEBUG::2013-03-20 09:54:35,282::task::957::TaskManager.Task::(_decref) Task=`fa8e34a1-a011-4a0b-bd9e-403f43e14eeb`::ref 0 aborting False MainThread::INFO::2013-03-20 09:54:45,576::vmChannels::135::vds::(stop) VM channels listener was stopped. MainThread::DEBUG::2013-03-20 09:54:45,583::task::568::TaskManager.Task::(_updateState) Task=`7126b7b5-adfa-4b37-b79f-6ea716d4a77f`::moving from state init -> state preparing MainThread::INFO::2013-03-20 09:54:45,583::logUtils::37::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None) Thread-11::DEBUG::2013-03-20 09:54:45,584::storageServer::674::ConnectionMonitor::(_monitorConnections) Monitoring stopped MainThread::DEBUG::2013-03-20 09:54:45,676::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks MainThread::INFO::2013-03-20 09:54:45,676::logUtils::39::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None MainThread::DEBUG::2013-03-20 09:54:45,676::task::1151::TaskManager.Task::(prepare) Task=`7126b7b5-adfa-4b37-b79f-6ea716d4a77f`::finished: None MainThread::DEBUG::2013-03-20 09:54:45,676::task::568::TaskManager.Task::(_updateState) Task=`7126b7b5-adfa-4b37-b79f-6ea716d4a77f`::moving from state preparing -> state finished MainThread::DEBUG::2013-03-20 09:54:45,676::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} MainThread::DEBUG::2013-03-20 09:54:45,677::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} MainThread::DEBUG::2013-03-20 09:54:45,677::task::957::TaskManager.Task::(_decref) Task=`7126b7b5-adfa-4b37-b79f-6ea716d4a77f`::ref 0 aborting False MainThread::INFO::2013-03-20 09:54:45,677::vdsm::94::vds::(run) VDSM main thread ended. Waiting for 13 other threads... MainThread::INFO::2013-03-20 09:54:45,677::vdsm::98::vds::(run) <_MainThread(MainThread, started 140397066807040)> MainThread::INFO::2013-03-20 09:54:45,677::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:54:45,677::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:54:45,677::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:54:45,677::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:54:45,677::vmChannels::135::vds::(stop) VM channels listener was stopped. MainThread::INFO::2013-03-20 09:54:45,678::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:54:45,678::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:54:45,678::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:54:45,678::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:54:45,678::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:54:45,678::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:54:45,678::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:54:45,678::vdsm::98::vds::(run) MainThread::INFO::2013-03-20 09:54:45,678::vdsm::98::vds::(run)