Re: [Users] creating and running a vm fails

Thursday, 29 March 2012

Hi,

here the creation process:

Thread-1688::DEBUG::2012-03-29 10:43:19,814::vm::577::vm.Vm::(_startUnderlyingVm)
vmId=`eda8737f-204f-4a33-8d24-49c4276309b5`::_ongoingCreations released
Thread-1688::ERROR::2012-03-29 10:43:19,849::vm::601::vm.Vm::(_startUnderlyingVm)
vmId=`eda8737f-204f-4a33-8d24-49c4276309b5`::The vm start process failed
Traceback (most recent call last):
  File "/usr/share/vdsm/vm.py", line 567, in _startUnderlyingVm
    self._run()
  File "/usr/share/vdsm/libvirtvm.py", line 1315, in _run
    self._connection.createXML(domxml, flags),
  File "/usr/share/vdsm/libvirtconnection.py", line 82, in wrapper
    ret = f(*args, **kwargs)
  File "/usr/lib64/python2.6/site-packages/libvirt.py", line 2087, in createXML
    if ret is None:raise libvirtError('virDomainCreateXML() failed', conn=self)
libvirtError: internal error Process exited while reading console log output: Supported
machines are:
pc         RHEL 6.2.0 PC (alias of rhel6.2.0)
rhel6.2.0  RHEL 6.2.0 PC (default)
rhel6.1.0  RHEL 6.1.0 PC
rhel6.0.0  RHEL 6.0.0 PC
rhel5.5.0  RHEL 5.5.0 PC
rhel5.4.4  RHEL 5.4.4 PC
rhel5.4.0  RHEL 5.4.0 PC

Thread-1688::DEBUG::2012-03-29 10:43:19,876::vm::919::vm.Vm::(setDownStatus)
vmId=`eda8737f-204f-4a33-8d24-49c4276309b5`::Changed state to Down: internal error Process
exited while reading console log output: Supported machines are:
pc         RHEL 6.2.0 PC (alias of rhel6.2.0)
rhel6.2.0  RHEL 6.2.0 PC (default)
rhel6.1.0  RHEL 6.1.0 PC
rhel6.0.0  RHEL 6.0.0 PC
rhel5.5.0  RHEL 5.5.0 PC
rhel5.4.4  RHEL 5.4.4 PC
rhel5.4.0  RHEL 5.4.0 PC

Thread-1694::DEBUG::2012-03-29 10:43:20,231::BindingXMLRPC::869::vds::(wrapper) client
[192.168.100.10]::call vmGetStats with ('eda8737f-204f-4a33-8d24-49c4276309b5',)
{} flowID [4dfa400f]
Thread-1694::DEBUG::2012-03-29 10:43:20,278::BindingXMLRPC::875::vds::(wrapper) return
vmGetStats with {'status': {'message': 'Done', 'code': 0},
'statsList': [{'status': 'Down', 'hash': '0',
'exitMessage': 'internal error Process exited while reading console log
output: Supported machines are:\npc         RHEL 6.2.0 PC (alias of rhel6.2.0)\nrhel6.2.0 
RHEL 6.2.0 PC (default)\nrhel6.1.0  RHEL 6.1.0 PC\nrhel6.0.0  RHEL 6.0.0 PC\nrhel5.5.0 
RHEL 5.5.0 PC\nrhel5.4.4  RHEL 5.4.4 PC\nrhel5.4.0  RHEL 5.4.0 PC\n', 'vmId':
'eda8737f-204f-4a33-8d24-49c4276309b5', 'timeOffset': '0',
'exitCode': 1}]}
Thread-1695::DEBUG::2012-03-29 10:43:20,294::BindingXMLRPC::869::vds::(wrapper) client
[192.168.100.10]::call vmDestroy with ('eda8737f-204f-4a33-8d24-49c4276309b5',) {}
flowID [4dfa400f]
Thread-1695::INFO::2012-03-29 10:43:20,296::API::300::vds::(destroy) vmContainerLock
acquired by vm eda8737f-204f-4a33-8d24-49c4276309b5
Thread-1695::DEBUG::2012-03-29 10:43:20,298::libvirtvm::2016::vm.Vm::(destroy)
vmId=`eda8737f-204f-4a33-8d24-49c4276309b5`::destroy Called
Thread-1695::INFO::2012-03-29 10:43:20,300::libvirtvm::1978::vm.Vm::(releaseVm)
vmId=`eda8737f-204f-4a33-8d24-49c4276309b5`::Release VM resources
Thread-1695::WARNING::2012-03-29 10:43:20,301::vm::327::vm.Vm::(_set_lastStatus)
vmId=`eda8737f-204f-4a33-8d24-49c4276309b5`::trying to set state to Powering down when
already Down
Thread-1695::DEBUG::2012-03-29 10:43:20,304::utils::602::Storage.Misc.excCmd::(execCmd)
'/usr/bin/sudo -n /sbin/service ksmtuned retune' (cwd None)
Thread-1695::DEBUG::2012-03-29 10:43:20,505::utils::602::Storage.Misc.excCmd::(execCmd)
SUCCESS: <err> = ''; <rc> = 0
Thread-1695::DEBUG::2012-03-29 10:43:20,512::task::588::TaskManager.Task::(_updateState)
Task=`21a70ac7-d608-4d94-9d8b-5d69da80a9d8`::moving from state init -> state preparing
Thread-1695::INFO::2012-03-29 10:43:20,514::logUtils::37::dispatcher::(wrapper) Run and
protect: inappropriateDevices(thiefId='eda8737f-204f-4a33-8d24-49c4276309b5')
Thread-1695::INFO::2012-03-29 10:43:20,527::logUtils::39::dispatcher::(wrapper) Run and
protect: inappropriateDevices, Return response: None
Thread-1695::DEBUG::2012-03-29 10:43:20,529::task::1172::TaskManager.Task::(prepare)
Task=`21a70ac7-d608-4d94-9d8b-5d69da80a9d8`::finished: None
Thread-1695::DEBUG::2012-03-29 10:43:20,531::task::588::TaskManager.Task::(_updateState)
Task=`21a70ac7-d608-4d94-9d8b-5d69da80a9d8`::moving from state preparing -> state
finished

I want to create a cntos6.2 vm.

Regards, rene

-----Ursprüngliche Nachricht-----
Von: Moran Goldboim [mailto:mgoldboi@redhat.com]
Gesendet: Donnerstag, 29. März 2012 10:11
An: Rene Rosenberger
Cc: users(a)oVirt.org
Betreff: Re: AW: [Users] creating and running a vm fails

Rene, this log doesn't contain the run vm command either it's not
getting there or log snip doesn't contain it. the verb is: call vmCreate
Trail it when you are trying to run the vm on that host.
are you still getting same logs on the engine?

Moran.

On 03/29/2012 09:53 AM, Rene Rosenberger wrote:
...
 Hi,

 this is what vdms.log says on the host i want to run the vm:

 Thread-55012::DEBUG::2012-03-29
09:51:02,514::resourceManager::486::ResourceManager::(registerResource) Trying to register
resource 'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a' for lock type
'shared'
 Thread-55012::DEBUG::2012-03-29
09:51:02,516::resourceManager::528::ResourceManager::(registerResource) Resource
'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a' is free. Now locking as
'shared' (1 active user)
 Thread-55012::DEBUG::2012-03-29
09:51:02,518::resourceManager::212::ResourceManager.Request::(grant)
ResName=`Storage.13080edc-77ea-11e1-b6a4-525400c49d2a`ReqID=`2c8c0dd9-feef-431f-a246-d8a6ae2a6fe1`::Granted
request
 Thread-55012::DEBUG::2012-03-29
09:51:02,521::task::817::TaskManager.Task::(resourceAcquired)
Task=`2f85e9fd-3ae4-4ecc-9b42-53543228fcd4`::_resourcesAcquired:
Storage.13080edc-77ea-11e1-b6a4-525400c49d2a (shared)
 Thread-55012::DEBUG::2012-03-29 09:51:02,523::task::978::TaskManager.Task::(_decref)
Task=`2f85e9fd-3ae4-4ecc-9b42-53543228fcd4`::ref 1 aborting False
 Thread-55012::INFO::2012-03-29 09:51:02,529::logUtils::39::dispatcher::(wrapper) Run and
protect: getStoragePoolInfo, Return response: {'info': {'spm_id': 1,
'master_uuid': '8ed25a57-f53a-4cf0-bb92-781f3ce36a48', 'name':
'Default', 'version': '2', 'domains':
u'93e2079e-ef3b-452f-af71-5b3e7eb32ba0:Active,bb13e29f-0e5a-4f79-8bf2-f235a0dbd515:Active,8ed25a57-f53a-4cf0-bb92-781f3ce36a48:Active',
'pool_status': 'connected', 'isoprefix':
u'/rhev/data-center/13080edc-77ea-11e1-b6a4-525400c49d2a/93e2079e-ef3b-452f-af71-5b3e7eb32ba0/images/11111111-1111-1111-1111-111111111111',
'type': 'ISCSI', 'master_ver': 1, 'lver': 1},
'dominfo': {u'93e2079e-ef3b-452f-af71-5b3e7eb32ba0': {'status':
u'Active', 'diskfree': '235838373888', 'alerts': [],
'disktotal': '257822818304'},
u'8ed25a57-f53a-4cf0-bb92-781f3ce36a48': {'status': u'Active',
'diskfree': '2141846503424', 'alerts': [], 'disktotal':
'2147080994816'}, u'bb13e29f-0e5a-4f79-8bf2-f235a0dbd515':
{'status': u'Active', 'diskfree': '5267626524672',
'alerts': [], 'disktotal': '5902284816384'}}}
 Thread-55012::DEBUG::2012-03-29 09:51:02,531::task::1172::TaskManager.Task::(prepare)
Task=`2f85e9fd-3ae4-4ecc-9b42-53543228fcd4`::finished: {'info': {'spm_id':
1, 'master_uuid': '8ed25a57-f53a-4cf0-bb92-781f3ce36a48', 'name':
'Default', 'version': '2', 'domains':
u'93e2079e-ef3b-452f-af71-5b3e7eb32ba0:Active,bb13e29f-0e5a-4f79-8bf2-f235a0dbd515:Active,8ed25a57-f53a-4cf0-bb92-781f3ce36a48:Active',
'pool_status': 'connected', 'isoprefix':
u'/rhev/data-center/13080edc-77ea-11e1-b6a4-525400c49d2a/93e2079e-ef3b-452f-af71-5b3e7eb32ba0/images/11111111-1111-1111-1111-111111111111',
'type': 'ISCSI', 'master_ver': 1, 'lver': 1},
'dominfo': {u'93e2079e-ef3b-452f-af71-5b3e7eb32ba0': {'status':
u'Active', 'diskfree': '235838373888', 'alerts': [],
'disktotal': '257822818304'},
u'8ed25a57-f53a-4cf0-bb92-781f3ce36a48': {'status': u'Active',
'diskfree': '2141846503424', 'alerts': [], 'disktotal':
'2147080994816'}, u'bb13e29f-0e5a-4f79-8bf2-f235a0dbd515':
{'status': u'Active', 'diskfree': '5267626524672',
'alerts': [], 'disktotal': '5902284816384'}}}
 Thread-55012::DEBUG::2012-03-29 09:51:02,533::task::588::TaskManager.Task::(_updateState)
Task=`2f85e9fd-3ae4-4ecc-9b42-53543228fcd4`::moving from state preparing ->  state
finished
 Thread-55012::DEBUG::2012-03-29
09:51:02,535::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a':< 
ResourceRef 'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a', isValid:
'True' obj: 'None'>}
 Thread-55012::DEBUG::2012-03-29
09:51:02,536::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
 Thread-55012::DEBUG::2012-03-29
09:51:02,539::resourceManager::538::ResourceManager::(releaseResource) Trying to release
resource 'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a'
 Thread-55012::DEBUG::2012-03-29
09:51:02,541::resourceManager::553::ResourceManager::(releaseResource) Released resource
'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a' (0 active users)
 Thread-55012::DEBUG::2012-03-29
09:51:02,542::resourceManager::558::ResourceManager::(releaseResource) Resource
'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a' is free, finding out if anyone is
waiting for it.
 Thread-55012::DEBUG::2012-03-29
09:51:02,544::resourceManager::565::ResourceManager::(releaseResource) No one is waiting
for resource 'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a', Clearing records.
 Thread-55012::DEBUG::2012-03-29 09:51:02,546::task::978::TaskManager.Task::(_decref)
Task=`2f85e9fd-3ae4-4ecc-9b42-53543228fcd4`::ref 0 aborting False
 Dummy-93::DEBUG::2012-03-29
09:51:03,920::storage_mailbox::640::Storage.Misc.excCmd::(_checkForMail) 'dd
if=/rhev/data-center/13080edc-77ea-11e1-b6a4-525400c49d2a/mastersd/dom_md/inbox
iflag=direct,fullblock count=1 bs=1024000' (cwd None)
 Dummy-93::DEBUG::2012-03-29
09:51:04,372::storage_mailbox::640::Storage.Misc.excCmd::(_checkForMail)
SUCCESS:<err>  = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB)
copied, 0.187424 s, 5.5 MB/s\n';<rc>  = 0
 Dummy-93::DEBUG::2012-03-29
09:51:06,420::storage_mailbox::640::Storage.Misc.excCmd::(_checkForMail) 'dd
if=/rhev/data-center/13080edc-77ea-11e1-b6a4-525400c49d2a/mastersd/dom_md/inbox
iflag=direct,fullblock count=1 bs=1024000' (cwd None)
 Dummy-93::DEBUG::2012-03-29
09:51:06,895::storage_mailbox::640::Storage.Misc.excCmd::(_checkForMail)
SUCCESS:<err>  = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB)
copied, 0.209075 s, 4.9 MB/s\n';<rc>  = 0
 Dummy-93::DEBUG::2012-03-29
09:51:08,953::storage_mailbox::640::Storage.Misc.excCmd::(_checkForMail) 'dd
if=/rhev/data-center/13080edc-77ea-11e1-b6a4-525400c49d2a/mastersd/dom_md/inbox
iflag=direct,fullblock count=1 bs=1024000' (cwd None)
 Dummy-93::DEBUG::2012-03-29
09:51:09,403::storage_mailbox::640::Storage.Misc.excCmd::(_checkForMail)
SUCCESS:<err>  = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB)
copied, 0.187018 s, 5.5 MB/s\n';<rc>  = 0
 Thread-55016::DEBUG::2012-03-29 09:51:10,110::task::588::TaskManager.Task::(_updateState)
Task=`83108b7c-5bbd-4aad-bfb2-da6ebf87882f`::moving from state init ->  state
preparing
 Thread-55016::INFO::2012-03-29 09:51:10,113::logUtils::37::dispatcher::(wrapper) Run and
protect: repoStats(options=None)
 Thread-55016::INFO::2012-03-29 09:51:10,116::logUtils::39::dispatcher::(wrapper) Run and
protect: repoStats, Return response: {'93e2079e-ef3b-452f-af71-5b3e7eb32ba0':
{'delay': '0.00430202484131', 'lastCheck': 1333007465.9121721,
'code': 0, 'valid': True}, '8ed25a57-f53a-4cf0-bb92-781f3ce36a48':
{'delay': '0.00339603424072', 'lastCheck': 1333007467.4905169,
'code': 0, 'valid': True}, 'bb13e29f-0e5a-4f79-8bf2-f235a0dbd515':
{'delay': '0.00301098823547', 'lastCheck': 1333007468.0463679,
'code': 0, 'valid': True}}
 Thread-55016::DEBUG::2012-03-29 09:51:10,117::task::1172::TaskManager.Task::(prepare)
Task=`83108b7c-5bbd-4aad-bfb2-da6ebf87882f`::finished:
{'93e2079e-ef3b-452f-af71-5b3e7eb32ba0': {'delay':
'0.00430202484131', 'lastCheck': 1333007465.9121721, 'code': 0,
'valid': True}, '8ed25a57-f53a-4cf0-bb92-781f3ce36a48': {'delay':
'0.00339603424072', 'lastCheck': 1333007467.4905169, 'code': 0,
'valid': True}, 'bb13e29f-0e5a-4f79-8bf2-f235a0dbd515': {'delay':
'0.00301098823547', 'lastCheck': 1333007468.0463679, 'code': 0,
'valid': True}}
 Thread-55016::DEBUG::2012-03-29 09:51:10,120::task::588::TaskManager.Task::(_updateState)
Task=`83108b7c-5bbd-4aad-bfb2-da6ebf87882f`::moving from state preparing ->  state
finished
 Thread-55016::DEBUG::2012-03-29
09:51:10,121::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
 Thread-55016::DEBUG::2012-03-29
09:51:10,123::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
 Thread-55016::DEBUG::2012-03-29 09:51:10,125::task::978::TaskManager.Task::(_decref)
Task=`83108b7c-5bbd-4aad-bfb2-da6ebf87882f`::ref 0 aborting False
 Dummy-93::DEBUG::2012-03-29
09:51:11,451::storage_mailbox::640::Storage.Misc.excCmd::(_checkForMail) 'dd
if=/rhev/data-center/13080edc-77ea-11e1-b6a4-525400c49d2a/mastersd/dom_md/inbox
iflag=direct,fullblock count=1 bs=1024000' (cwd None)
 Dummy-93::DEBUG::2012-03-29
09:51:11,921::storage_mailbox::640::Storage.Misc.excCmd::(_checkForMail)
SUCCESS:<err>  = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB)
copied, 0.181907 s, 5.6 MB/s\n';<rc>  = 0
 Thread-55019::DEBUG::2012-03-29 09:51:12,583::BindingXMLRPC::167::vds::(wrapper)
[192.168.100.10]
 Thread-55019::DEBUG::2012-03-29 09:51:12,587::task::588::TaskManager.Task::(_updateState)
Task=`ec333fa9-0878-479f-a781-b91c236c2e50`::moving from state init ->  state
preparing
 Thread-55019::INFO::2012-03-29 09:51:12,589::logUtils::37::dispatcher::(wrapper) Run and
protect: getSpmStatus(spUUID='13080edc-77ea-11e1-b6a4-525400c49d2a',
options=None)
 Thread-55019::INFO::2012-03-29 09:51:12,592::logUtils::39::dispatcher::(wrapper) Run and
protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1,
'spmStatus': 'SPM', 'spmLver': 1}}
 Thread-55019::DEBUG::2012-03-29 09:51:12,593::task::1172::TaskManager.Task::(prepare)
Task=`ec333fa9-0878-479f-a781-b91c236c2e50`::finished: {'spm_st':
{'spmId': 1, 'spmStatus': 'SPM', 'spmLver': 1}}
 Thread-55019::DEBUG::2012-03-29 09:51:12,595::task::588::TaskManager.Task::(_updateState)
Task=`ec333fa9-0878-479f-a781-b91c236c2e50`::moving from state preparing ->  state
finished
 Thread-55019::DEBUG::2012-03-29
09:51:12,597::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
 Thread-55019::DEBUG::2012-03-29
09:51:12,598::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
 Thread-55019::DEBUG::2012-03-29 09:51:12,600::task::978::TaskManager.Task::(_decref)
Task=`ec333fa9-0878-479f-a781-b91c236c2e50`::ref 0 aborting False
 Thread-55020::DEBUG::2012-03-29 09:51:12,610::BindingXMLRPC::167::vds::(wrapper)
[192.168.100.10]
 Thread-55020::DEBUG::2012-03-29 09:51:12,613::task::588::TaskManager.Task::(_updateState)
Task=`67cf8ade-753b-4a9f-9f06-9991412582b8`::moving from state init ->  state
preparing
 Thread-55020::INFO::2012-03-29 09:51:12,615::logUtils::37::dispatcher::(wrapper) Run and
protect: getStoragePoolInfo(spUUID='13080edc-77ea-11e1-b6a4-525400c49d2a',
options=None)
 Thread-55020::DEBUG::2012-03-29
09:51:12,619::resourceManager::175::ResourceManager.Request::(__init__)
ResName=`Storage.13080edc-77ea-11e1-b6a4-525400c49d2a`ReqID=`4a7a5857-9d8c-4f4c-8177-2386473f98d7`::Request
was made in '/usr/share/vdsm/storage/hsm.py' line '2037' at
'getStoragePoolInfo'
 Thread-55020::DEBUG::2012-03-29
09:51:12,620::resourceManager::486::ResourceManager::(registerResource) Trying to register
resource 'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a' for lock type
'shared'
 Thread-55020::DEBUG::2012-03-29
09:51:12,622::resourceManager::528::ResourceManager::(registerResource) Resource
'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a' is free. Now locking as
'shared' (1 active user)
 Thread-55020::DEBUG::2012-03-29
09:51:12,624::resourceManager::212::ResourceManager.Request::(grant)
ResName=`Storage.13080edc-77ea-11e1-b6a4-525400c49d2a`ReqID=`4a7a5857-9d8c-4f4c-8177-2386473f98d7`::Granted
request
 Thread-55020::DEBUG::2012-03-29
09:51:12,632::task::817::TaskManager.Task::(resourceAcquired)
Task=`67cf8ade-753b-4a9f-9f06-9991412582b8`::_resourcesAcquired:
Storage.13080edc-77ea-11e1-b6a4-525400c49d2a (shared)
 Thread-55020::DEBUG::2012-03-29 09:51:12,634::task::978::TaskManager.Task::(_decref)
Task=`67cf8ade-753b-4a9f-9f06-9991412582b8`::ref 1 aborting False
 Thread-55020::INFO::2012-03-29 09:51:12,640::logUtils::39::dispatcher::(wrapper) Run and
protect: getStoragePoolInfo, Return response: {'info': {'spm_id': 1,
'master_uuid': '8ed25a57-f53a-4cf0-bb92-781f3ce36a48', 'name':
'Default', 'version': '2', 'domains':
u'93e2079e-ef3b-452f-af71-5b3e7eb32ba0:Active,bb13e29f-0e5a-4f79-8bf2-f235a0dbd515:Active,8ed25a57-f53a-4cf0-bb92-781f3ce36a48:Active',
'pool_status': 'connected', 'isoprefix':
u'/rhev/data-center/13080edc-77ea-11e1-b6a4-525400c49d2a/93e2079e-ef3b-452f-af71-5b3e7eb32ba0/images/11111111-1111-1111-1111-111111111111',
'type': 'ISCSI', 'master_ver': 1, 'lver': 1},
'dominfo': {u'93e2079e-ef3b-452f-af71-5b3e7eb32ba0': {'status':
u'Active', 'diskfree': '235838373888', 'alerts': [],
'disktotal': '257822818304'},
u'8ed25a57-f53a-4cf0-bb92-781f3ce36a48': {'status': u'Active',
'diskfree': '2141846503424', 'alerts': [], 'disktotal':
'2147080994816'}, u'bb13e29f-0e5a-4f79-8bf2-f235a0dbd515':
{'status': u'Active', 'diskfree': '5267626524672',
'alerts': [], 'disktotal': '5902284816384'}}}
 Thread-55020::DEBUG::2012-03-29 09:51:12,642::task::1172::TaskManager.Task::(prepare)
Task=`67cf8ade-753b-4a9f-9f06-9991412582b8`::finished: {'info': {'spm_id':
1, 'master_uuid': '8ed25a57-f53a-4cf0-bb92-781f3ce36a48', 'name':
'Default', 'version': '2', 'domains':
u'93e2079e-ef3b-452f-af71-5b3e7eb32ba0:Active,bb13e29f-0e5a-4f79-8bf2-f235a0dbd515:Active,8ed25a57-f53a-4cf0-bb92-781f3ce36a48:Active',
'pool_status': 'connected', 'isoprefix':
u'/rhev/data-center/13080edc-77ea-11e1-b6a4-525400c49d2a/93e2079e-ef3b-452f-af71-5b3e7eb32ba0/images/11111111-1111-1111-1111-111111111111',
'type': 'ISCSI', 'master_ver': 1, 'lver': 1},
'dominfo': {u'93e2079e-ef3b-452f-af71-5b3e7eb32ba0': {'status':
u'Active', 'diskfree': '235838373888', 'alerts': [],
'disktotal': '257822818304'},
u'8ed25a57-f53a-4cf0-bb92-781f3ce36a48': {'status': u'Active',
'diskfree': '2141846503424', 'alerts': [], 'disktotal':
'2147080994816'}, u'bb13e29f-0e5a-4f79-8bf2-f235a0dbd515':
{'status': u'Active', 'diskfree': '5267626524672',
'alerts': [], 'disktotal': '5902284816384'}}}
 Thread-55020::DEBUG::2012-03-29 09:51:12,644::task::588::TaskManager.Task::(_updateState)
Task=`67cf8ade-753b-4a9f-9f06-9991412582b8`::moving from state preparing ->  state
finished
 Thread-55020::DEBUG::2012-03-29
09:51:12,646::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a':< 
ResourceRef 'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a', isValid:
'True' obj: 'None'>}
 Thread-55020::DEBUG::2012-03-29
09:51:12,648::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
 Thread-55020::DEBUG::2012-03-29
09:51:12,650::resourceManager::538::ResourceManager::(releaseResource) Trying to release
resource 'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a'
 Thread-55020::DEBUG::2012-03-29
09:51:12,652::resourceManager::553::ResourceManager::(releaseResource) Released resource
'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a' (0 active users)
 Thread-55020::DEBUG::2012-03-29
09:51:12,653::resourceManager::558::ResourceManager::(releaseResource) Resource
'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a' is free, finding out if anyone is
waiting for it.
 Thread-55020::DEBUG::2012-03-29
09:51:12,655::resourceManager::565::ResourceManager::(releaseResource) No one is waiting
for resource 'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a', Clearing records.
 Thread-55020::DEBUG::2012-03-29 09:51:12,657::task::978::TaskManager.Task::(_decref)
Task=`67cf8ade-753b-4a9f-9f06-9991412582b8`::ref 0 aborting False
 Dummy-93::DEBUG::2012-03-29
09:51:13,970::storage_mailbox::640::Storage.Misc.excCmd::(_checkForMail) 'dd
if=/rhev/data-center/13080edc-77ea-11e1-b6a4-525400c49d2a/mastersd/dom_md/inbox
iflag=direct,fullblock count=1 bs=1024000' (cwd None)
 Dummy-93::DEBUG::2012-03-29
09:51:14,422::storage_mailbox::640::Storage.Misc.excCmd::(_checkForMail)
SUCCESS:<err>  = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB)
copied, 0.194021 s, 5.3 MB/s\n';<rc>  = 0
 Dummy-93::DEBUG::2012-03-29
09:51:16,469::storage_mailbox::640::Storage.Misc.excCmd::(_checkForMail) 'dd
if=/rhev/data-center/13080edc-77ea-11e1-b6a4-525400c49d2a/mastersd/dom_md/inbox
iflag=direct,fullblock count=1 bs=1024000' (cwd None)
 Dummy-93::DEBUG::2012-03-29
09:51:16,962::storage_mailbox::640::Storage.Misc.excCmd::(_checkForMail)
SUCCESS:<err>  = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB)
copied, 0.187019 s, 5.5 MB/s\n';<rc>  = 0
 Dummy-93::DEBUG::2012-03-29
09:51:19,009::storage_mailbox::640::Storage.Misc.excCmd::(_checkForMail) 'dd
if=/rhev/data-center/13080edc-77ea-11e1-b6a4-525400c49d2a/mastersd/dom_md/inbox
iflag=direct,fullblock count=1 bs=1024000' (cwd None)
 Dummy-93::DEBUG::2012-03-29
09:51:19,451::storage_mailbox::640::Storage.Misc.excCmd::(_checkForMail)
SUCCESS:<err>  = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB)
copied, 0.18092 s, 5.7 MB/s\n';<rc>  = 0
 Thread-55024::DEBUG::2012-03-29 09:51:20,246::task::588::TaskManager.Task::(_updateState)
Task=`73e39a42-ee05-459f-9d83-b1329d987665`::moving from state init ->  state
preparing
 Thread-55024::INFO::2012-03-29 09:51:20,249::logUtils::37::dispatcher::(wrapper) Run and
protect: repoStats(options=None)
 Thread-55024::INFO::2012-03-29 09:51:20,252::logUtils::39::dispatcher::(wrapper) Run and
protect: repoStats, Return response: {'93e2079e-ef3b-452f-af71-5b3e7eb32ba0':
{'delay': '0.00443387031555', 'lastCheck': 1333007475.9278209,
'code': 0, 'valid': True}, '8ed25a57-f53a-4cf0-bb92-781f3ce36a48':
{'delay': '0.00118398666382', 'lastCheck': 1333007477.502805,
'code': 0, 'valid': True}, 'bb13e29f-0e5a-4f79-8bf2-f235a0dbd515':
{'delay': '0.00273203849792', 'lastCheck': 1333007478.0588491,
'code': 0, 'valid': True}}
 Thread-55024::DEBUG::2012-03-29 09:51:20,253::task::1172::TaskManager.Task::(prepare)
Task=`73e39a42-ee05-459f-9d83-b1329d987665`::finished:
{'93e2079e-ef3b-452f-af71-5b3e7eb32ba0': {'delay':
'0.00443387031555', 'lastCheck': 1333007475.9278209, 'code': 0,
'valid': True}, '8ed25a57-f53a-4cf0-bb92-781f3ce36a48': {'delay':
'0.00118398666382', 'lastCheck': 1333007477.502805, 'code': 0,
'valid': True}, 'bb13e29f-0e5a-4f79-8bf2-f235a0dbd515': {'delay':
'0.00273203849792', 'lastCheck': 1333007478.0588491, 'code': 0,
'valid': True}}
 Thread-55024::DEBUG::2012-03-29 09:51:20,256::task::588::TaskManager.Task::(_updateState)
Task=`73e39a42-ee05-459f-9d83-b1329d987665`::moving from state preparing ->  state
finished
 Thread-55024::DEBUG::2012-03-29
09:51:20,257::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
 Thread-55024::DEBUG::2012-03-29
09:51:20,259::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
 Thread-55024::DEBUG::2012-03-29 09:51:20,261::task::978::TaskManager.Task::(_decref)
Task=`73e39a42-ee05-459f-9d83-b1329d987665`::ref 0 aborting False
 Dummy-93::DEBUG::2012-03-29
09:51:21,502::storage_mailbox::640::Storage.Misc.excCmd::(_checkForMail) 'dd
if=/rhev/data-center/13080edc-77ea-11e1-b6a4-525400c49d2a/mastersd/dom_md/inbox
iflag=direct,fullblock count=1 bs=1024000' (cwd None)
 Dummy-93::DEBUG::2012-03-29
09:51:21,950::storage_mailbox::640::Storage.Misc.excCmd::(_checkForMail)
SUCCESS:<err>  = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB)
copied, 0.179002 s, 5.7 MB/s\n';<rc>  = 0
 Thread-55027::DEBUG::2012-03-29 09:51:22,700::BindingXMLRPC::167::vds::(wrapper)
[192.168.100.10]
 Thread-55027::DEBUG::2012-03-29 09:51:22,704::task::588::TaskManager.Task::(_updateState)
Task=`f6e28785-c757-4b89-87ce-c92286bc1bc2`::moving from state init ->  state
preparing
 Thread-55027::INFO::2012-03-29 09:51:22,706::logUtils::37::dispatcher::(wrapper) Run and
protect: getSpmStatus(spUUID='13080edc-77ea-11e1-b6a4-525400c49d2a',
options=None)
 Thread-55027::INFO::2012-03-29 09:51:22,709::logUtils::39::dispatcher::(wrapper) Run and
protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1,
'spmStatus': 'SPM', 'spmLver': 1}}
 Thread-55027::DEBUG::2012-03-29 09:51:22,711::task::1172::TaskManager.Task::(prepare)
Task=`f6e28785-c757-4b89-87ce-c92286bc1bc2`::finished: {'spm_st':
{'spmId': 1, 'spmStatus': 'SPM', 'spmLver': 1}}
 Thread-55027::DEBUG::2012-03-29 09:51:22,712::task::588::TaskManager.Task::(_updateState)
Task=`f6e28785-c757-4b89-87ce-c92286bc1bc2`::moving from state preparing ->  state
finished
 Thread-55027::DEBUG::2012-03-29
09:51:22,714::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
 Thread-55027::DEBUG::2012-03-29
09:51:22,716::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
 Thread-55027::DEBUG::2012-03-29 09:51:22,717::task::978::TaskManager.Task::(_decref)
Task=`f6e28785-c757-4b89-87ce-c92286bc1bc2`::ref 0 aborting False
 Thread-55028::DEBUG::2012-03-29 09:51:22,727::BindingXMLRPC::167::vds::(wrapper)
[192.168.100.10]
 Thread-55028::DEBUG::2012-03-29 09:51:22,730::task::588::TaskManager.Task::(_updateState)
Task=`22afe74b-e4a8-421b-84b3-6c9295dce788`::moving from state init ->  state
preparing
 Thread-55028::INFO::2012-03-29 09:51:22,732::logUtils::37::dispatcher::(wrapper) Run and
protect: getStoragePoolInfo(spUUID='13080edc-77ea-11e1-b6a4-525400c49d2a',
options=None)
 Thread-55028::DEBUG::2012-03-29
09:51:22,735::resourceManager::175::ResourceManager.Request::(__init__)
ResName=`Storage.13080edc-77ea-11e1-b6a4-525400c49d2a`ReqID=`8e695a8f-e8b2-4ab6-a464-4447e37f0fe5`::Request
was made in '/usr/share/vdsm/storage/hsm.py' line '2037' at
'getStoragePoolInfo'
 Thread-55028::DEBUG::2012-03-29
09:51:22,737::resourceManager::486::ResourceManager::(registerResource) Trying to register
resource 'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a' for lock type
'shared'
 Thread-55028::DEBUG::2012-03-29
09:51:22,739::resourceManager::528::ResourceManager::(registerResource) Resource
'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a' is free. Now locking as
'shared' (1 active user)
 Thread-55028::DEBUG::2012-03-29
09:51:22,741::resourceManager::212::ResourceManager.Request::(grant)
ResName=`Storage.13080edc-77ea-11e1-b6a4-525400c49d2a`ReqID=`8e695a8f-e8b2-4ab6-a464-4447e37f0fe5`::Granted
request
 Thread-55028::DEBUG::2012-03-29
09:51:22,743::task::817::TaskManager.Task::(resourceAcquired)
Task=`22afe74b-e4a8-421b-84b3-6c9295dce788`::_resourcesAcquired:
Storage.13080edc-77ea-11e1-b6a4-525400c49d2a (shared)
 Thread-55028::DEBUG::2012-03-29 09:51:22,745::task::978::TaskManager.Task::(_decref)
Task=`22afe74b-e4a8-421b-84b3-6c9295dce788`::ref 1 aborting False
 Thread-55028::INFO::2012-03-29 09:51:22,752::logUtils::39::dispatcher::(wrapper) Run and
protect: getStoragePoolInfo, Return response: {'info': {'spm_id': 1,
'master_uuid': '8ed25a57-f53a-4cf0-bb92-781f3ce36a48', 'name':
'Default', 'version': '2', 'domains':
u'93e2079e-ef3b-452f-af71-5b3e7eb32ba0:Active,bb13e29f-0e5a-4f79-8bf2-f235a0dbd515:Active,8ed25a57-f53a-4cf0-bb92-781f3ce36a48:Active',
'pool_status': 'connected', 'isoprefix':
u'/rhev/data-center/13080edc-77ea-11e1-b6a4-525400c49d2a/93e2079e-ef3b-452f-af71-5b3e7eb32ba0/images/11111111-1111-1111-1111-111111111111',
'type': 'ISCSI', 'master_ver': 1, 'lver': 1},
'dominfo': {u'93e2079e-ef3b-452f-af71-5b3e7eb32ba0': {'status':
u'Active', 'diskfree': '235838373888', 'alerts': [],
'disktotal': '257822818304'},
u'8ed25a57-f53a-4cf0-bb92-781f3ce36a48': {'status': u'Active',
'diskfree': '2141846503424', 'alerts': [], 'disktotal':
'2147080994816'}, u'bb13e29f-0e5a-4f79-8bf2-f235a0dbd515':
{'status': u'Active', 'diskfree': '5267626524672',
'alerts': [], 'disktotal': '5902284816384'}}}
 Thread-55028::DEBUG::2012-03-29 09:51:22,753::task::1172::TaskManager.Task::(prepare)
Task=`22afe74b-e4a8-421b-84b3-6c9295dce788`::finished: {'info': {'spm_id':
1, 'master_uuid': '8ed25a57-f53a-4cf0-bb92-781f3ce36a48', 'name':
'Default', 'version': '2', 'domains':
u'93e2079e-ef3b-452f-af71-5b3e7eb32ba0:Active,bb13e29f-0e5a-4f79-8bf2-f235a0dbd515:Active,8ed25a57-f53a-4cf0-bb92-781f3ce36a48:Active',
'pool_status': 'connected', 'isoprefix':
u'/rhev/data-center/13080edc-77ea-11e1-b6a4-525400c49d2a/93e2079e-ef3b-452f-af71-5b3e7eb32ba0/images/11111111-1111-1111-1111-111111111111',
'type': 'ISCSI', 'master_ver': 1, 'lver': 1},
'dominfo': {u'93e2079e-ef3b-452f-af71-5b3e7eb32ba0': {'status':
u'Active', 'diskfree': '235838373888', 'alerts': [],
'disktotal': '257822818304'},
u'8ed25a57-f53a-4cf0-bb92-781f3ce36a48': {'status': u'Active',
'diskfree': '2141846503424', 'alerts': [], 'disktotal':
'2147080994816'}, u'bb13e29f-0e5a-4f79-8bf2-f235a0dbd515':
{'status': u'Active', 'diskfree': '5267626524672',
'alerts': [], 'disktotal': '5902284816384'}}}
 Thread-55028::DEBUG::2012-03-29 09:51:22,756::task::588::TaskManager.Task::(_updateState)
Task=`22afe74b-e4a8-421b-84b3-6c9295dce788`::moving from state preparing ->  state
finished
 Thread-55028::DEBUG::2012-03-29
09:51:22,757::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a':< 
ResourceRef 'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a', isValid:
'True' obj: 'None'>}
 Thread-55028::DEBUG::2012-03-29
09:51:22,759::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
 Thread-55028::DEBUG::2012-03-29
09:51:22,761::resourceManager::538::ResourceManager::(releaseResource) Trying to release
resource 'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a'
 Thread-55028::DEBUG::2012-03-29
09:51:22,763::resourceManager::553::ResourceManager::(releaseResource) Released resource
'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a' (0 active users)
 Thread-55028::DEBUG::2012-03-29
09:51:22,764::resourceManager::558::ResourceManager::(releaseResource) Resource
'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a' is free, finding out if anyone is
waiting for it.
 Thread-55028::DEBUG::2012-03-29
09:51:22,766::resourceManager::565::ResourceManager::(releaseResource) No one is waiting
for resource 'Storage.13080edc-77ea-11e1-b6a4-525400c49d2a', Clearing records.
 Thread-55028::DEBUG::2012-03-29 09:51:22,768::task::978::TaskManager.Task::(_decref)
Task=`22afe74b-e4a8-421b-84b3-6c9295dce788`::ref 0 aborting False
 Dummy-93::DEBUG::2012-03-29
09:51:23,999::storage_mailbox::640::Storage.Misc.excCmd::(_checkForMail) 'dd
if=/rhev/data-center/13080edc-77ea-11e1-b6a4-525400c49d2a/mastersd/dom_md/inbox
iflag=direct,fullblock count=1 bs=1024000' (cwd None)
 Dummy-93::DEBUG::2012-03-29
09:51:24,459::storage_mailbox::640::Storage.Misc.excCmd::(_checkForMail)
SUCCESS:<err>  = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB)
copied, 0.178758 s, 5.7 MB/s\n';<rc>  = 0
 Dummy-93::DEBUG::2012-03-29
09:51:26,507::storage_mailbox::640::Storage.Misc.excCmd::(_checkForMail) 'dd
if=/rhev/data-center/13080edc-77ea-11e1-b6a4-525400c49d2a/mastersd/dom_md/inbox
iflag=direct,fullblock count=1 bs=1024000' (cwd None)

 Regards, rene

 -----Ursprüngliche Nachricht-----
 Von: users-bounces(a)ovirt.org [mailto:users-bounces@ovirt.org] Im Auftrag von Rene
Rosenberger
 Gesendet: Donnerstag, 29. März 2012 09:32
 An: Moran Goldboim
 Cc: users(a)oVirt.org
 Betreff: Re: [Users] creating and running a vm fails

 Hi,

 i have just retried to start the vm what fails again. Looking in /var/log/vsdm/vdsm.log
shows last entry on 27.03.2012.

 MainThread::INFO::2012-03-27 10:58:13,525::vdsm::70::vds::(run) I am the actual vdsm
4.9-0
 MainThread::DEBUG::2012-03-27
10:58:15,120::resourceManager::379::ResourceManager::(registerNamespace) Registering
namespace 'Storage'
 MainThread::DEBUG::2012-03-27 10:58:15,122::threadPool::45::Misc.ThreadPool::(__init__)
Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0
 MainThread::DEBUG::2012-03-27
10:58:15,393::multipath::109::Storage.Multipath::(isEnabled) multipath Defaulting to
False
 MainThread::DEBUG::2012-03-27
10:58:15,398::multipath::123::Storage.Misc.excCmd::(setupMultipath) '/usr/bin/sudo -n
/bin/cp /tmp/tmpkart5V /etc/multipath.conf' (cwd None)
 MainThread::DEBUG::2012-03-27
10:58:15,505::multipath::123::Storage.Misc.excCmd::(setupMultipath) SUCCESS:<err>  =
'';<rc>  = 0
 MainThread::DEBUG::2012-03-27
10:58:15,508::multipath::131::Storage.Misc.excCmd::(setupMultipath) '/usr/bin/sudo -n
/sbin/multipath -F' (cwd None)
 MainThread::DEBUG::2012-03-27
10:58:15,591::multipath::131::Storage.Misc.excCmd::(setupMultipath) FAILED:<err>  =
'';<rc>  = 1
 MainThread::DEBUG::2012-03-27
10:58:15,600::multipath::134::Storage.Misc.excCmd::(setupMultipath) '/usr/bin/sudo -n
/sbin/service multipathd restart' (cwd None)
 MainThread::DEBUG::2012-03-27
10:58:16,123::multipath::134::Storage.Misc.excCmd::(setupMultipath) SUCCESS:<err>  =
'';<rc>  = 0
 MainThread::DEBUG::2012-03-27
10:58:16,130::hsm::334::Storage.Misc.excCmd::(__validateLvmLockingType) '/usr/bin/sudo
-n /sbin/lvm dumpconfig global/locking_type' (cwd None)
 MainThread::DEBUG::2012-03-27
10:58:16,424::hsm::334::Storage.Misc.excCmd::(__validateLvmLockingType)
SUCCESS:<err>  = '';<rc>  = 0
 MainThread::DEBUG::2012-03-27 10:58:16,428::lvm::316::OperationMutex::(_reloadpvs)
Operation 'lvm reload operation' got the operation mutex
 MainThread::DEBUG::2012-03-27 10:58:16,434::lvm::284::Storage.Misc.excCmd::(cmd)
'/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::2012-03-27 10:58:16,708::lvm::284::Storage.Misc.excCmd::(cmd)
SUCCESS:<err>  = '';<rc>  = 0
 MainThread::DEBUG::2012-03-27 10:58:16,711::lvm::339::OperationMutex::(_reloadpvs)
Operation 'lvm reload operation' released the operation mutex
 MainThread::DEBUG::2012-03-27 10:58:16,712::lvm::349::OperationMutex::(_reloadvgs)
Operation 'lvm reload operation' got the operation mutex
 MainThread::DEBUG::2012-03-27 10:58:16,713::lvm::284::Storage.Misc.excCmd::(cmd)
'/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::2012-03-27 10:58:16,906::lvm::284::Storage.Misc.excCmd::(cmd)
SUCCESS:<err>  = '  No volume groups found\n';<rc>  = 0
 MainThread::DEBUG::2012-03-27 10:58:16,909::lvm::376::OperationMutex::(_reloadvgs)
Operation 'lvm reload operation' released the operation mutex
 MainThread::DEBUG::2012-03-27 10:58:16,910::lvm::284::Storage.Misc.excCmd::(cmd)
'/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)
 MainThread::DEBUG::2012-03-27 10:58:17,119::lvm::284::Storage.Misc.excCmd::(cmd)
SUCCESS:<err>  = '  No volume groups found\n';<rc>  = 0
 Thread-12::DEBUG::2012-03-27 10:58:17,123::misc::1022::SamplingMethod::(__call__) Trying
to enter sampling method (storage.sdc.refreshStorage)
 MainThread::INFO::2012-03-27
10:58:17,130::dispatcher::118::Storage.Dispatcher::(__init__) Starting
StorageDispatcher...
 Thread-12::DEBUG::2012-03-27 10:58:17,132::misc::1024::SamplingMethod::(__call__) Got in
to sampling method
 Thread-12::DEBUG::2012-03-27 10:58:17,141::misc::1022::SamplingMethod::(__call__) Trying
to enter sampling method (storage.iscsi.rescan)
 Thread-12::DEBUG::2012-03-27 10:58:17,142::misc::1024::SamplingMethod::(__call__) Got in
to sampling method
 Thread-12::DEBUG::2012-03-27 10:58:17,147::iscsiadm::48::Storage.Misc.excCmd::(_runCmd)
'/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
 MainThread::ERROR::2012-03-27 10:58:17,164::netinfo::126::root::(speed) cannot read eth0
speed Traceback (most recent call last):
    File "/usr/lib/python2.6/site-packages/vdsm/netinfo.py", line 113, in speed
      s = int(file('/sys/class/net/%s/speed' % dev).read())
 IOError: [Errno 22] Invalid argument
 MainThread::DEBUG::2012-03-27 10:58:17,198::utils::602::Storage.Misc.excCmd::(execCmd)
'/usr/bin/pgrep -xf ksmd' (cwd None)
 Thread-12::DEBUG::2012-03-27 10:58:17,297::iscsiadm::48::Storage.Misc.excCmd::(_runCmd)
FAILED:<err>  = 'iscsiadm: No session found.\n';<rc>  = 21
 Thread-12::DEBUG::2012-03-27 10:58:17,304::misc::1032::SamplingMethod::(__call__)
Returning last result
 Thread-12::DEBUG::2012-03-27
10:58:17,306::supervdsm::83::SuperVdsmProxy::(_killSupervdsm) Could not kill old Super
Vdsm [Errno 2] No such file or directory: '/var/run/vdsm/svdsm.pid'
 Thread-12::DEBUG::2012-03-27
10:58:17,308::supervdsm::71::SuperVdsmProxy::(_launchSupervdsm) Launching Super Vdsm
 Thread-12::DEBUG::2012-03-27
10:58:17,309::supervdsm::74::Storage.Misc.excCmd::(_launchSupervdsm) '/usr/bin/sudo -n
/usr/bin/python /usr/share/vdsm/supervdsmServer.pyc f90ef831-7bff-4eb4-a9b5-890538959b22
2858' (cwd None)
 MainThread::DEBUG::2012-03-27 10:58:17,390::utils::602::Storage.Misc.excCmd::(execCmd)
SUCCESS:<err>  = '';<rc>  = 0
 MainThread::INFO::2012-03-27 10:58:17,438::vmChannels::139::vds::(settimeout) Setting
channels' timeout to 30 seconds.
 VM Channels Listener::INFO::2012-03-27 10:58:17,524::vmChannels::127::vds::(run) Starting
VM channels listener thread.
 MainThread::DEBUG::2012-03-27
10:58:17,864::supervdsmServer::201::SuperVdsm.Server::(main) Making sure I'm root
 MainThread::DEBUG::2012-03-27
10:58:17,866::supervdsmServer::205::SuperVdsm.Server::(main) Parsing cmd args
 MainThread::DEBUG::2012-03-27
10:58:17,867::supervdsmServer::208::SuperVdsm.Server::(main) Creating PID file
 MainThread::DEBUG::2012-03-27
10:58:17,867::supervdsmServer::212::SuperVdsm.Server::(main) Cleaning old socket
 MainThread::DEBUG::2012-03-27
10:58:17,868::supervdsmServer::216::SuperVdsm.Server::(main) Setting up keep alive thread
 MainThread::DEBUG::2012-03-27
10:58:17,887::supervdsmServer::221::SuperVdsm.Server::(main) Creating remote object
manager
 MainThread::DEBUG::2012-03-27
10:58:17,894::supervdsmServer::232::SuperVdsm.Server::(main) Started serving super vdsm
object
 Thread-12::DEBUG::2012-03-27 10:58:19,378::supervdsm::92::SuperVdsmProxy::(_connect)
Trying to connect to Super Vdsm
 Thread-12::DEBUG::2012-03-27 10:58:19,431::supervdsm::64::SuperVdsmProxy::(__init__)
Connected to Super Vdsm
 Thread-12::DEBUG::2012-03-27 10:58:19,737::multipath::71::Storage.Misc.excCmd::(rescan)
'/usr/bin/sudo -n /sbin/multipath' (cwd None)
 Thread-12::DEBUG::2012-03-27 10:58:19,838::multipath::71::Storage.Misc.excCmd::(rescan)
FAILED:<err>  = '';<rc>  = 1
 Thread-12::DEBUG::2012-03-27 10:58:19,841::lvm::457::OperationMutex::(_invalidateAllPvs)
Operation 'lvm invalidate operation' got the operation mutex
 Thread-12::DEBUG::2012-03-27 10:58:19,842::lvm::459::OperationMutex::(_invalidateAllPvs)
Operation 'lvm invalidate operation' released the operation mutex
 Thread-12::DEBUG::2012-03-27 10:58:19,843::lvm::469::OperationMutex::(_invalidateAllVgs)
Operation 'lvm invalidate operation' got the operation mutex
 Thread-12::DEBUG::2012-03-27 10:58:19,844::lvm::471::OperationMutex::(_invalidateAllVgs)
Operation 'lvm invalidate operation' released the operation mutex
 Thread-12::DEBUG::2012-03-27 10:58:19,844::lvm::490::OperationMutex::(_invalidateAllLvs)
Operation 'lvm invalidate operation' got the operation mutex
 Thread-12::DEBUG::2012-03-27 10:58:19,845::lvm::492::OperationMutex::(_invalidateAllLvs)
Operation 'lvm invalidate operation' released the operation mutex
 Thread-12::DEBUG::2012-03-27 10:58:19,846::misc::1032::SamplingMethod::(__call__)
Returning last result
 Thread-12::DEBUG::2012-03-27
10:58:19,847::hsm::358::Storage.HSM::(__cleanStorageRepository) Started cleaning storage
repository at '/rhev/data-center'
 Thread-12::DEBUG::2012-03-27
10:58:19,853::hsm::390::Storage.HSM::(__cleanStorageRepository) White list:
['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*',
'/rhev/data-center/mnt']
 Thread-12::DEBUG::2012-03-27
10:58:19,857::hsm::391::Storage.HSM::(__cleanStorageRepository) Mount list: []
 Thread-12::DEBUG::2012-03-27
10:58:19,857::hsm::393::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers
 Thread-12::DEBUG::2012-03-27
10:58:19,858::hsm::436::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage
repository at '/rhev/data-center'

 Regards, rene

 -----Ursprüngliche Nachricht-----
 Von: Moran Goldboim [mailto:mgoldboi@redhat.com]
 Gesendet: Donnerstag, 29. März 2012 09:06
 An: Rene Rosenberger
 Cc: Itamar Heim; users(a)oVirt.org
 Betreff: Re: [Users] creating and running a vm fails

 I suspect something happened to vdsm - can you attach vdsm logs
 (/var/log/vdsm/vdsm.log) from that time and maybe sneak a pick at /var/log/core if we
have something there.
 Moran.

 On 03/29/2012 08:07 AM, Rene Rosenberger wrote:
> Hi,
>
> the host on which the vm should run is up. It has a green arrow.
>
> Regards, rene
>
>
> -----Ursprüngliche Nachricht-----
> Von: Itamar Heim [mailto:iheim@redhat.com]
> Gesendet: Mittwoch, 28. März 2012 22:07
> An: Rene Rosenberger
> Cc: users(a)oVirt.org
> Betreff: Re: [Users] creating and running a vm fails
>
> On 03/28/2012 02:33 PM, Rene Rosenberger wrote:
>> Hi,
>>
>> when i create a VM with it virtual disk and i want to run it once to
>> install from imported iso file I get the following error message:
>>
>> 2012-03-28 14:31:35,488
>> INFO[org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand]
>> (http--0.0.0.0-8443-5) [cf5d84e] START, CreateVmVDSCommand(vdsId =
>> 0e0403a4-78ae-11e1-9c19-525400c49d2a,
>> vmId=93220e0a-610a-4b20-986e-3c8b0d39e35f,
>> vm=org.ovirt.engine.core.common.businessentities.VM@6e69e491), log id:
>> 3fc82aad
>>
>> 2012-03-28 14:31:35,498
>> INFO[org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
>> (http--0.0.0.0-8443-5) [cf5d84e] START, CreateVDSCommand(vdsId =
>> 0e0403a4-78ae-11e1-9c19-525400c49d2a,
>> vmId=93220e0a-610a-4b20-986e-3c8b0d39e35f,
>> vm=org.ovirt.engine.core.common.businessentities.VM@6e69e491), log id:
>> 7e63d56b
>>
>> 2012-03-28 14:31:35,620
>> INFO[org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
>> (http--0.0.0.0-8443-5) [cf5d84e]
>> org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand
>> spiceSslCipherSuite=DEFAULT,memSize=512,kvmEnable=true,boot=dc,smp=1,
>> e
>> mulatedMachine=pc-0.14,vmType=kvm,keyboardLayout=en-us,pitReinjection
>> =
>> false,nice=0,display=vnc,tabletEnable=true,smpCoresPerSocket=1,spiceS
>> e
>> cureChannels=,spiceMonitors=1,cdrom=/rhev/data-center/13080edc-77ea-1
>> 1
>> e1-b6a4-525400c49d2a/93e2079e-ef3b-452f-af71-5b3e7eb32ba0/images/1111
>> 1
>> 111-1111-1111-1111-111111111111/CentOS-6.2-x86_64-bin-DVD1.iso,timeOf
>> f
>> set=0,transparentHugePages=true,drives=[Ljava.util.Map;@7f0ba1c1,vmId
>> =
>> 93220e0a-610a-4b20-986e-3c8b0d39e35f,acpiEnable=true,vmName=test,cpuT
>> y
>> pe=Opteron_G3,custom={}
>>
>> 2012-03-28 14:31:35,620
>> INFO[org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
>> (http--0.0.0.0-8443-5) [cf5d84e] FINISH, CreateVDSCommand, log id:
>> 7e63d56b
>>
>> 2012-03-28 14:31:35,625
>> INFO[org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand]
>> (http--0.0.0.0-8443-5) [cf5d84e]
>> IncreasePendingVms::CreateVmIncreasing
>> vds KVM-DMZ-04 pending vcpu count, now 1. Vm: test
>>
>> 2012-03-28 14:31:35,631
>> INFO[org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand]
>> (http--0.0.0.0-8443-5) [cf5d84e] FINISH, CreateVmVDSCommand, return:
>> WaitForLaunch, log id: 3fc82aad
>>
>> 2012-03-28 14:31:39,316
>> WARN[org.ovirt.engine.core.vdsbroker.VdsManager]
>> (QuartzScheduler_Worker-35)
>> ResourceManager::refreshVdsRunTimeInfo::Failed to refresh VDS , vds =
>> 0e0403a4-78ae-11e1-9c19-525400c49d2a : KVM-DMZ-04, VDS Network Error,
>> continuing.
>>
>> VDSNetworkException:
>>
>> 2012-03-28 14:31:41,328
>> WARN[org.ovirt.engine.core.vdsbroker.VdsManager]
>> (QuartzScheduler_Worker-29)
>> ResourceManager::refreshVdsRunTimeInfo::Failed to refresh VDS , vds =
>> 0e0403a4-78ae-11e1-9c19-525400c49d2a : KVM-DMZ-04, VDS Network Error,
>> continuing.
>>
>> VDSNetworkException:
>>
>> 2012-03-28 14:31:43,340
>> WARN[org.ovirt.engine.core.vdsbroker.VdsManager]
>> (QuartzScheduler_Worker-45)
>> ResourceManager::refreshVdsRunTimeInfo::Failed to refresh VDS , vds =
>> 0e0403a4-78ae-11e1-9c19-525400c49d2a : KVM-DMZ-04, VDS Network Error,
>> continuing.
>>
>> VDSNetworkException:
>>
>> 2012-03-28 14:31:43,519
>> INFO[org.ovirt.engine.core.bll.storage.SetStoragePoolStatusCommand]
>> (QuartzScheduler_Worker-38) [7ed2f412] Running command:
>> SetStoragePoolStatusCommand internal: true. Entities affected :ID:
>> 13080edc-77ea-11e1-b6a4-525400c49d2a Type: StoragePool
>>
>> 2012-03-28 14:31:43,543 ERROR
>> [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
>> (QuartzScheduler_Worker-38) [7ed2f412]
>> IrsBroker::Failed::GetStoragePoolInfoVDS due to: ConnectException:
>> Connection refused
>>
>> 2012-03-28 14:31:45,351
>> WARN[org.ovirt.engine.core.vdsbroker.VdsManager]
>> (QuartzScheduler_Worker-47)
>> ResourceManager::refreshVdsRunTimeInfo::Failed to refresh VDS , vds =
>> 0e0403a4-78ae-11e1-9c19-525400c49d2a : KVM-DMZ-04, VDS Network Error,
>> continuing.
>>
>> VDSNetworkException:
>>
>> 2012-03-28 14:31:47,363
>> WARN[org.ovirt.engine.core.vdsbroker.VdsManager]
>> (QuartzScheduler_Worker-71)
>> ResourceManager::refreshVdsRunTimeInfo::Failed to refresh VDS , vds =
>> 0e0403a4-78ae-11e1-9c19-525400c49d2a : KVM-DMZ-04, VDS Network Error,
>> continuing.
>>
>> VDSNetworkException:
>>
>> 2012-03-28 14:31:51,091
>> INFO[org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
>> (QuartzScheduler_Worker-55) vm test running in db and not running in
>> vds
>> - add to rerun treatment. vds KVM-DMZ-04
>>
>> 2012-03-28 14:31:51,104
>> INFO[org.ovirt.engine.core.bll.InitVdsOnUpCommand]
>> (QuartzScheduler_Worker-55) [6df61eca] Running command:
>> InitVdsOnUpCommand internal: true.
>>
>> 2012-03-28 14:31:51,182
>> INFO[org.ovirt.engine.core.bll.storage.ConnectHostToStoragePoolServer
>> s
>> Command]
>> (QuartzScheduler_Worker-55) [48a331d9] Running command:
>> ConnectHostToStoragePoolServersCommand internal: true. Entities
>> affected
>> :ID: 13080edc-77ea-11e1-b6a4-525400c49d2a Type: StoragePool
>>
>> 2012-03-28 14:31:51,185
>> INFO[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVD
>> S
>> Command]
>> (QuartzScheduler_Worker-55) [48a331d9] START,
>> ConnectStorageServerVDSCommand(vdsId =
>> 0e0403a4-78ae-11e1-9c19-525400c49d2a, storagePoolId =
>> 13080edc-77ea-11e1-b6a4-525400c49d2a, storageType = ISCSI,
>> connectionList = [{ id: e25e5093-9240-42ac-a21a-f0c216294944,
>> connection: 192.168.200.32 };]), log id: 11a3b069
>>
>> 2012-03-28 14:31:51,488
>> INFO[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVD
>> S
>> Command]
>> (QuartzScheduler_Worker-55) [48a331d9] FINISH,
>> ConnectStorageServerVDSCommand, return:
>> {e25e5093-9240-42ac-a21a-f0c216294944=0}, log id: 11a3b069
>>
>> 2012-03-28 14:31:51,489
>> INFO[org.ovirt.engine.core.bll.storage.ConnectHostToStoragePoolServer
>> s
>> Command]
>> (QuartzScheduler_Worker-55) [48a331d9] Host KVM-DMZ-04 storage
>> connection was succeeded
>>
>> 2012-03-28 14:31:51,492
>> INFO[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVD
>> S
>> Command]
>> (QuartzScheduler_Worker-55) [48a331d9] START,
>> ConnectStorageServerVDSCommand(vdsId =
>> 0e0403a4-78ae-11e1-9c19-525400c49d2a, storagePoolId =
>> 13080edc-77ea-11e1-b6a4-525400c49d2a, storageType = NFS,
>> connectionList = [{ id: 3dd798da-77ea-11e1-969c-525400c49d2a, connection:
>> oVirt.dynetic.de:/mnt/iso };]), log id: 1d73fc4e
>>
>> 2012-03-28 14:31:51,535
>> INFO[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVD
>> S
>> Command]
>> (QuartzScheduler_Worker-55) [48a331d9] FINISH,
>> ConnectStorageServerVDSCommand, return:
>> {3dd798da-77ea-11e1-969c-525400c49d2a=0}, log id: 1d73fc4e
>>
>> 2012-03-28 14:31:51,535
>> INFO[org.ovirt.engine.core.bll.storage.ConnectHostToStoragePoolServer
>> s
>> Command]
>> (QuartzScheduler_Worker-55) [48a331d9] Host KVM-DMZ-04 storage
>> connection was succeeded
>>
>> 2012-03-28 14:31:51,538
>> INFO[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVD
>> S
>> Command]
>> (QuartzScheduler_Worker-55) [48a331d9] START,
>> ConnectStorageServerVDSCommand(vdsId =
>> 0e0403a4-78ae-11e1-9c19-525400c49d2a, storagePoolId =
>> 13080edc-77ea-11e1-b6a4-525400c49d2a, storageType = NFS,
>> connectionList = [{ id: 57d6595f-1109-49f9-a7f3-f8fe255c34bd, connection:
>> 192.168.200.32:/nfsexport };]), log id: 618343ee
>>
>> 2012-03-28 14:31:51,579
>> INFO[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVD
>> S
>> Command]
>> (QuartzScheduler_Worker-55) [48a331d9] FINISH,
>> ConnectStorageServerVDSCommand, return:
>> {57d6595f-1109-49f9-a7f3-f8fe255c34bd=0}, log id: 618343ee
>>
>> 2012-03-28 14:31:51,579
>> INFO[org.ovirt.engine.core.bll.storage.ConnectHostToStoragePoolServer
>> s
>> Command]
>> (QuartzScheduler_Worker-55) [48a331d9] Host KVM-DMZ-04 storage
>> connection was succeeded
>>
>> 2012-03-28 14:31:51,594
>> INFO[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSC
>> o
>> mmand]
>> (QuartzScheduler_Worker-55) [48a331d9] START,
>> ConnectStoragePoolVDSCommand(vdsId =
>> 0e0403a4-78ae-11e1-9c19-525400c49d2a, storagePoolId =
>> 13080edc-77ea-11e1-b6a4-525400c49d2a, vds_spm_id = 1, masterDomainId
>> = 8ed25a57-f53a-4cf0-bb92-781f3ce36a48, masterVersion = 1), log id:
>> 190d7dea
>>
>> 2012-03-28 14:32:02,207
>> INFO[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSC
>> o
>> mmand]
>> (QuartzScheduler_Worker-55) [48a331d9] FINISH,
>> ConnectStoragePoolVDSCommand, log id: 190d7dea
>>
>> 2012-03-28 14:32:02,231
>> INFO[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDire
>> c
>> tor]
>> (QuartzScheduler_Worker-55) [48a331d9] No string for UNASSIGNED type.
>> Use default Log
>>
>> 2012-03-28 14:32:02,234
>> INFO[org.ovirt.engine.core.bll.MultipleActionsRunner]
>> (pool-5-thread-47) [48a331d9] MultipleActionsRunner of type
>> MigrateVmToServer invoked with no actions
>>
>> 2012-03-28 14:32:02,264
>> INFO[org.ovirt.engine.core.bll.HandleVdsCpuFlagsOrClusterChangedComma
>> n
>> d]
>> (QuartzScheduler_Worker-55) [75839ca5] Running command:
>> HandleVdsCpuFlagsOrClusterChangedCommand internal: true. Entities
>> affected :ID: 0e0403a4-78ae-11e1-9c19-525400c49d2a Type: VDS
>>
>> 2012-03-28 14:32:02,272
>> INFO[org.ovirt.engine.core.bll.HandleVdsVersionCommand]
>> (QuartzScheduler_Worker-55) [2dd7e7a] Running command:
>> HandleVdsVersionCommand internal: true. Entities affected :ID:
>> 0e0403a4-78ae-11e1-9c19-525400c49d2a Type: VDS
>>
>> 2012-03-28 14:32:02,276 ERROR
>> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
>> (QuartzScheduler_Worker-55) [2dd7e7a] Rerun vm
>> 93220e0a-610a-4b20-986e-3c8b0d39e35f. Called from vds KVM-DMZ-04
>>
>> 2012-03-28 14:32:02,280
>> INFO[org.ovirt.engine.core.vdsbroker.UpdateVdsDynamicDataVDSCommand]
>> (pool-5-thread-47) [2dd7e7a] START,
>> UpdateVdsDynamicDataVDSCommand(vdsId
>> = 0e0403a4-78ae-11e1-9c19-525400c49d2a,
>> vdsDynamic=org.ovirt.engine.core.common.businessentities.VdsDynamic@2
>> f
>> 1f5a9f),
>> log id: 2901421c
>>
>> 2012-03-28 14:32:02,282
>> INFO[org.ovirt.engine.core.vdsbroker.UpdateVdsDynamicDataVDSCommand]
>> (pool-5-thread-47) [2dd7e7a] FINISH, UpdateVdsDynamicDataVDSCommand,
>> log
>> id: 2901421c
>>
>> 2012-03-28 14:32:02,299
>> INFO[org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
>> (pool-5-thread-47) [2dd7e7a] START, IsValidVDSCommand(storagePoolId =
>> 13080edc-77ea-11e1-b6a4-525400c49d2a, ignoreFailoverLimit = false,
>> compatabilityVersion = null), log id: 2d73522e
>>
>> 2012-03-28 14:32:02,300
>> INFO[org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
>> (pool-5-thread-47) [2dd7e7a] FINISH, IsValidVDSCommand, return:
>> false, log id: 2d73522e
>>
>> 2012-03-28 14:32:02,301
>> WARN[org.ovirt.engine.core.bll.RunVmOnceCommand]
>> (pool-5-thread-47) [2dd7e7a] CanDoAction of action RunVmOnce failed.
>> Reasons:VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM
>> , ACTION_TYPE_FAILED_IMAGE_REPOSITORY_NOT_FOUND
>>
>> 2012-03-28 14:32:04,591
>> INFO[org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
>> (QuartzScheduler_Worker-62) hostFromVds::selectedVds - KVM-DMZ-04,
>> spmStatus Free, storage pool Default
>>
>> 2012-03-28 14:32:05,430
>> INFO[org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
>> (QuartzScheduler_Worker-62) SpmStatus on vds
>> 0e0403a4-78ae-11e1-9c19-525400c49d2a: Free
>>
>> 2012-03-28 14:32:05,436
>> INFO[org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
>> (QuartzScheduler_Worker-62) starting spm on vds KVM-DMZ-04, storage
>> pool Default, prevId 1, LVER 0
>>
>> 2012-03-28 14:32:05,439
>> INFO[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
>> (QuartzScheduler_Worker-62) START, SpmStartVDSCommand(vdsId =
>> 0e0403a4-78ae-11e1-9c19-525400c49d2a, storagePoolId =
>> 13080edc-77ea-11e1-b6a4-525400c49d2a, prevId=1, prevLVER=0,
>> storagePoolFormatType=V2, recoveryMode=Manual, SCSIFencing=false),
>> log
>> id: 25d38cf4
>>
>> 2012-03-28 14:32:05,490
>> INFO[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
>> (QuartzScheduler_Worker-62) spmStart polling started: taskId =
>> c2a0d9a2-e356-4aa9-bb29-f66a0899d8cc
>>
>> Any idea what to do?
>>
> looks like the host is no up?
> _______________________________________________
> Users mailing list
> Users(a)ovirt.org
> http://lists.ovirt.org/mailman/listinfo/users
 _______________________________________________
 Users mailing list
 Users(a)ovirt.org
 http://lists.ovirt.org/mailman/listinfo/users 

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

Re: [Users] creating and running a vm fails