Attachment 617594 Details for Bug 860719 – vdsm.log

vdsm.log

vdsm.log (text/x-log), 85.14 KB, created by Jakub Libosvar on 2012-09-26 14:49:44 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Jakub Libosvar

Created: 2012-09-26 14:49:44 UTC

Size: 85.14 KB

patch

obsolete

>Thread-142901::DEBUG::2012-09-26 15:30:48,528::BindingXMLRPC::164::vds::(wrapper) [10.34.63.27]
>Thread-142901::DEBUG::2012-09-26 15:30:48,529::task::588::TaskManager.Task::(_updateState) Task=`5ca899e0-76a3-472c-a6e1-44e585047b4f`::moving from state init -> state preparing
>Thread-142901::INFO::2012-09-26 15:30:48,531::logUtils::37::dispatcher::(wrapper) Run and protect: discoverSendTargets(con={'connection': '10.34.63.202', 'password': '******', 'port': '3260', 'user': ''}, options=None)
>Thread-142901::DEBUG::2012-09-26 15:30:48,532::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m discoverydb -t sendtargets -I default -p 10.34.63.202:3260 --op=new' (cwd None)
>Thread-142901::DEBUG::2012-09-26 15:30:48,563::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-142901::DEBUG::2012-09-26 15:30:48,564::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m discoverydb -t sendtargets -I default -p 10.34.63.202:3260 -n node.startup -v manual --op=update' (cwd None)
>Thread-142901::DEBUG::2012-09-26 15:30:48,592::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: Cannot modify node.startup. Invalid param name.\n'; <rc> = 7
>Thread-142901::DEBUG::2012-09-26 15:30:48,593::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m iface' (cwd None)
>Thread-142901::DEBUG::2012-09-26 15:30:48,622::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-142901::DEBUG::2012-09-26 15:30:48,623::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m discoverydb -t sendtargets -I default -p 10.34.63.202:3260 --discover' (cwd None)
>Thread-142901::DEBUG::2012-09-26 15:30:48,659::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-142901::DEBUG::2012-09-26 15:30:48,660::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m discoverydb -t sendtargets -I default -p 10.34.63.202:3260 --op=delete' (cwd None)
>Thread-142901::DEBUG::2012-09-26 15:30:48,688::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-142901::INFO::2012-09-26 15:30:48,689::logUtils::39::dispatcher::(wrapper) Run and protect: discoverSendTargets, Return response: {'fullTargets': ['10.34.63.202:3260,1 iqn.2012-06.brq.str-01:brq-setup', '10.34.63.202:3260,1 iqn.2011-01.brq.str-01:pstehlik'], 'targets': ['iqn.2012-06.brq.str-01:brq-setup', 'iqn.2011-01.brq.str-01:pstehlik']}
>Thread-142901::DEBUG::2012-09-26 15:30:48,695::task::1172::TaskManager.Task::(prepare) Task=`5ca899e0-76a3-472c-a6e1-44e585047b4f`::finished: {'fullTargets': ['10.34.63.202:3260,1 iqn.2012-06.brq.str-01:brq-setup', '10.34.63.202:3260,1 iqn.2011-01.brq.str-01:pstehlik'], 'targets': ['iqn.2012-06.brq.str-01:brq-setup', 'iqn.2011-01.brq.str-01:pstehlik']}
>Thread-142901::DEBUG::2012-09-26 15:30:48,695::task::588::TaskManager.Task::(_updateState) Task=`5ca899e0-76a3-472c-a6e1-44e585047b4f`::moving from state preparing -> state finished
>Thread-142901::DEBUG::2012-09-26 15:30:48,696::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142901::DEBUG::2012-09-26 15:30:48,696::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142901::DEBUG::2012-09-26 15:30:48,697::task::978::TaskManager.Task::(_decref) Task=`5ca899e0-76a3-472c-a6e1-44e585047b4f`::ref 0 aborting False
>Thread-142903::DEBUG::2012-09-26 15:30:50,606::BindingXMLRPC::164::vds::(wrapper) [10.34.63.27]
>Thread-142903::DEBUG::2012-09-26 15:30:50,607::task::588::TaskManager.Task::(_updateState) Task=`015b5530-7823-4494-8aef-46e1fe1f0bd2`::moving from state init -> state preparing
>Thread-142903::INFO::2012-09-26 15:30:50,607::logUtils::37::dispatcher::(wrapper) Run and protect: validateStorageServerConnection(domType=3, spUUID='00000000-0000-0000-0000-000000000000', conList=[{'connection': '10.34.63.202', 'iqn': 'iqn.2011-01.brq.str-01:pstehlik', 'portal': '0', 'user': '', 'password': '******', 'id': '00000000-0000-0000-0000-000000000000', 'port': '3260'}], options=None)
>Thread-142903::INFO::2012-09-26 15:30:50,608::logUtils::39::dispatcher::(wrapper) Run and protect: validateStorageServerConnection, Return response: {'statuslist': [{'status': 0, 'id': '00000000-0000-0000-0000-000000000000'}]}
>Thread-142903::DEBUG::2012-09-26 15:30:50,608::task::1172::TaskManager.Task::(prepare) Task=`015b5530-7823-4494-8aef-46e1fe1f0bd2`::finished: {'statuslist': [{'status': 0, 'id': '00000000-0000-0000-0000-000000000000'}]}
>Thread-142903::DEBUG::2012-09-26 15:30:50,609::task::588::TaskManager.Task::(_updateState) Task=`015b5530-7823-4494-8aef-46e1fe1f0bd2`::moving from state preparing -> state finished
>Thread-142903::DEBUG::2012-09-26 15:30:50,609::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142903::DEBUG::2012-09-26 15:30:50,609::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142903::DEBUG::2012-09-26 15:30:50,610::task::978::TaskManager.Task::(_decref) Task=`015b5530-7823-4494-8aef-46e1fe1f0bd2`::ref 0 aborting False
>Thread-142904::DEBUG::2012-09-26 15:30:50,623::BindingXMLRPC::164::vds::(wrapper) [10.34.63.27]
>Thread-142904::DEBUG::2012-09-26 15:30:50,624::task::588::TaskManager.Task::(_updateState) Task=`bc6c7f41-aa24-4eca-ab6e-fcd27e211d02`::moving from state init -> state preparing
>Thread-142904::INFO::2012-09-26 15:30:50,625::logUtils::37::dispatcher::(wrapper) Run and protect: connectStorageServer(domType=3, spUUID='00000000-0000-0000-0000-000000000000', conList=[{'connection': '10.34.63.202', 'iqn': 'iqn.2011-01.brq.str-01:pstehlik', 'portal': '0', 'user': '', 'password': '******', 'id': '00000000-0000-0000-0000-000000000000', 'port': '3260'}], options=None)
>Thread-142904::DEBUG::2012-09-26 15:30:50,625::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2011-01.brq.str-01:pstehlik -I default -p 10.34.63.202:3260 --op=new' (cwd None)
>Thread-142904::DEBUG::2012-09-26 15:30:50,659::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-142904::DEBUG::2012-09-26 15:30:50,660::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2011-01.brq.str-01:pstehlik -I default -p 10.34.63.202:3260 -l' (cwd None)
>Thread-142904::DEBUG::2012-09-26 15:30:51,219::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-142904::DEBUG::2012-09-26 15:30:51,220::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2011-01.brq.str-01:pstehlik -I default -p 10.34.63.202:3260 -n node.startup -v manual --op=update' (cwd None)
>Thread-142904::DEBUG::2012-09-26 15:30:51,271::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-142904::DEBUG::2012-09-26 15:30:51,272::lvm::460::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-142904::DEBUG::2012-09-26 15:30:51,273::lvm::462::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-142904::DEBUG::2012-09-26 15:30:51,274::lvm::472::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-142904::DEBUG::2012-09-26 15:30:51,275::lvm::474::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-142904::DEBUG::2012-09-26 15:30:51,276::lvm::493::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-142904::DEBUG::2012-09-26 15:30:51,276::lvm::495::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-142904::INFO::2012-09-26 15:30:51,277::logUtils::39::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {'statuslist': [{'status': 0, 'id': '00000000-0000-0000-0000-000000000000'}]}
>Thread-142904::DEBUG::2012-09-26 15:30:51,277::task::1172::TaskManager.Task::(prepare) Task=`bc6c7f41-aa24-4eca-ab6e-fcd27e211d02`::finished: {'statuslist': [{'status': 0, 'id': '00000000-0000-0000-0000-000000000000'}]}
>Thread-142904::DEBUG::2012-09-26 15:30:51,278::task::588::TaskManager.Task::(_updateState) Task=`bc6c7f41-aa24-4eca-ab6e-fcd27e211d02`::moving from state preparing -> state finished
>Thread-142904::DEBUG::2012-09-26 15:30:51,278::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142904::DEBUG::2012-09-26 15:30:51,278::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142904::DEBUG::2012-09-26 15:30:51,279::task::978::TaskManager.Task::(_decref) Task=`bc6c7f41-aa24-4eca-ab6e-fcd27e211d02`::ref 0 aborting False
>Thread-142906::DEBUG::2012-09-26 15:30:51,344::BindingXMLRPC::164::vds::(wrapper) [10.34.63.27]
>Thread-142906::DEBUG::2012-09-26 15:30:51,346::task::588::TaskManager.Task::(_updateState) Task=`f36bab81-34ce-4ee7-921b-363b46374b37`::moving from state init -> state preparing
>Thread-142906::INFO::2012-09-26 15:30:51,347::logUtils::37::dispatcher::(wrapper) Run and protect: getDeviceList(storageType=3, options={})
>Thread-142906::DEBUG::2012-09-26 15:30:51,348::misc::1080::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
>Thread-142906::DEBUG::2012-09-26 15:30:51,349::misc::1082::SamplingMethod::(__call__) Got in to sampling method
>Thread-142906::DEBUG::2012-09-26 15:30:51,350::misc::1080::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
>Thread-142906::DEBUG::2012-09-26 15:30:51,350::misc::1082::SamplingMethod::(__call__) Got in to sampling method
>Thread-142906::DEBUG::2012-09-26 15:30:51,351::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
>Thread-142906::DEBUG::2012-09-26 15:30:51,436::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-142906::DEBUG::2012-09-26 15:30:51,437::misc::1090::SamplingMethod::(__call__) Returning last result
>Thread-142906::DEBUG::2012-09-26 15:30:52,055::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None)
>Thread-142906::DEBUG::2012-09-26 15:30:52,257::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-142906::DEBUG::2012-09-26 15:30:52,257::lvm::460::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-142906::DEBUG::2012-09-26 15:30:52,258::lvm::462::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-142906::DEBUG::2012-09-26 15:30:52,259::lvm::472::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-142906::DEBUG::2012-09-26 15:30:52,259::lvm::474::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-142906::DEBUG::2012-09-26 15:30:52,260::lvm::493::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-142906::DEBUG::2012-09-26 15:30:52,260::lvm::495::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-142906::DEBUG::2012-09-26 15:30:52,261::misc::1090::SamplingMethod::(__call__) Returning last result
>Thread-142906::DEBUG::2012-09-26 15:30:52,261::lvm::319::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex
>Thread-142906::DEBUG::2012-09-26 15:30:52,264::__init__::1164::Storage.Misc.excCmd::(_log) '/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 = [ \\"a%1jlibosva|1ps01|1ps02|1pstehlik|36006048c0714062ba4b91f6a904bc07f|36006048c12952607a6254682d950135a|36006048c14e9eb8f668dfc53ea5995ca|36006048c78acaa6eac8ebc05bf73dee1|36006048cc786b195adb3de2b6d613cbc|36006048ce7ff8320bd02378f18cf9712%\\", \\"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)
>Thread-142906::DEBUG::2012-09-26 15:30:52,660::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-142906::DEBUG::2012-09-26 15:30:52,661::lvm::342::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,662::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/dmsetup status' (cwd None)
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,668::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,679::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/scsi_id --page=0x80 --whitelisted --export --replace-whitespace --device=/dev/dm-3' (cwd None)
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,683::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,687::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/scsi_id --page=0x80 --whitelisted --export --replace-whitespace --device=/dev/dm-4' (cwd None)
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,691::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,694::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/scsi_id --page=0x80 --whitelisted --export --replace-whitespace --device=/dev/dm-5' (cwd None)
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,698::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,702::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/scsi_id --page=0x80 --whitelisted --export --replace-whitespace --device=/dev/dm-6' (cwd None)
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,706::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,709::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/scsi_id --page=0x80 --whitelisted --export --replace-whitespace --device=/dev/dm-7' (cwd None)
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,713::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,716::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/scsi_id --page=0x80 --whitelisted --export --replace-whitespace --device=/dev/dm-8' (cwd None)
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,720::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,723::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/scsi_id --page=0x80 --whitelisted --export --replace-whitespace --device=/dev/dm-9' (cwd None)
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,727::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,731::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/scsi_id --page=0x80 --whitelisted --export --replace-whitespace --device=/dev/dm-10' (cwd None)
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,735::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,739::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/scsi_id --page=0x80 --whitelisted --export --replace-whitespace --device=/dev/dm-11' (cwd None)
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,744::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,747::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/scsi_id --page=0x80 --whitelisted --export --replace-whitespace --device=/dev/dm-12' (cwd None)
>MainProcess|Thread-142906::DEBUG::2012-09-26 15:30:52,751::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-142906::DEBUG::2012-09-26 15:30:52,755::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm pvcreate --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"a%1jlibosva|1ps01|1ps02|1pstehlik|36006048c0714062ba4b91f6a904bc07f|36006048c12952607a6254682d950135a|36006048c14e9eb8f668dfc53ea5995ca|36006048c78acaa6eac8ebc05bf73dee1|36006048cc786b195adb3de2b6d613cbc|36006048ce7ff8320bd02378f18cf9712%\\", \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --test --metadatasize 128m --metadatacopies 2 --metadataignore y /dev/mapper/36006048ce7ff8320bd02378f18cf9712 /dev/mapper/36006048c78acaa6eac8ebc05bf73dee1 /dev/mapper/36006048c14e9eb8f668dfc53ea5995ca /dev/mapper/36006048c12952607a6254682d950135a /dev/mapper/36006048c0714062ba4b91f6a904bc07f /dev/mapper/36006048cc786b195adb3de2b6d613cbc /dev/mapper/1jlibosva /dev/mapper/1ps01 /dev/mapper/1ps02 /dev/mapper/1pstehlik' (cwd None)
>Thread-142906::DEBUG::2012-09-26 15:30:53,805::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = '  Writing physical volume data to disk "/dev/mapper/36006048ce7ff8320bd02378f18cf9712"\n  Writing physical volume data to disk "/dev/mapper/36006048c78acaa6eac8ebc05bf73dee1"\n  Writing physical volume data to disk "/dev/mapper/36006048c14e9eb8f668dfc53ea5995ca"\n  Writing physical volume data to disk "/dev/mapper/36006048c12952607a6254682d950135a"\n  Writing physical volume data to disk "/dev/mapper/36006048c0714062ba4b91f6a904bc07f"\n  Writing physical volume data to disk "/dev/mapper/36006048cc786b195adb3de2b6d613cbc"\n  Writing physical volume data to disk "/dev/mapper/1jlibosva"\n  Writing physical volume data to disk "/dev/mapper/1ps01"\n  Writing physical volume data to disk "/dev/mapper/1ps02"\n  Can\'t initialize physical volume "/dev/mapper/1pstehlik" of volume group "57006b75-47ed-4119-b337-29fa010b8498" without -ff\n'; <rc> = 5
>Thread-142906::DEBUG::2012-09-26 15:30:53,808::lvm::751::Storage.LVM::(testPVCreate) rc: 5, out: ['  Test mode: Metadata will NOT be updated and volumes will not be (de)activated.', '  Physical volume "/dev/mapper/36006048ce7ff8320bd02378f18cf9712" successfully created', '  Physical volume "/dev/mapper/36006048c78acaa6eac8ebc05bf73dee1" successfully created', '  Physical volume "/dev/mapper/36006048c14e9eb8f668dfc53ea5995ca" successfully created', '  Physical volume "/dev/mapper/36006048c12952607a6254682d950135a" successfully created', '  Physical volume "/dev/mapper/36006048c0714062ba4b91f6a904bc07f" successfully created', '  Physical volume "/dev/mapper/36006048cc786b195adb3de2b6d613cbc" successfully created', '  Physical volume "/dev/mapper/1jlibosva" successfully created', '  Physical volume "/dev/mapper/1ps01" successfully created', '  Physical volume "/dev/mapper/1ps02" successfully created'], err: ['  Writing physical volume data to disk "/dev/mapper/36006048ce7ff8320bd02378f18cf9712"', '  Writing physical volume data to disk "/dev/mapper/36006048c78acaa6eac8ebc05bf73dee1"', '  Writing physical volume data to disk "/dev/mapper/36006048c14e9eb8f668dfc53ea5995ca"', '  Writing physical volume data to disk "/dev/mapper/36006048c12952607a6254682d950135a"', '  Writing physical volume data to disk "/dev/mapper/36006048c0714062ba4b91f6a904bc07f"', '  Writing physical volume data to disk "/dev/mapper/36006048cc786b195adb3de2b6d613cbc"', '  Writing physical volume data to disk "/dev/mapper/1jlibosva"', '  Writing physical volume data to disk "/dev/mapper/1ps01"', '  Writing physical volume data to disk "/dev/mapper/1ps02"', '  Can\'t initialize physical volume "/dev/mapper/1pstehlik" of volume group "57006b75-47ed-4119-b337-29fa010b8498" without -ff'], unusedDevs: set(['/dev/mapper/1jlibosva', '/dev/mapper/36006048c14e9eb8f668dfc53ea5995ca', '/dev/mapper/36006048c0714062ba4b91f6a904bc07f', '/dev/mapper/1ps02', '/dev/mapper/36006048c12952607a6254682d950135a', '/dev/mapper/1ps01', '/dev/mapper/36006048cc786b195adb3de2b6d613cbc', '/dev/mapper/36006048ce7ff8320bd02378f18cf9712', '/dev/mapper/36006048c78acaa6eac8ebc05bf73dee1']), usedDevs: set(['/dev/mapper/1pstehlik'])
>Thread-142906::INFO::2012-09-26 15:30:53,810::logUtils::39::dispatcher::(wrapper) Run and protect: getDeviceList, Return response: {'devList': [{'status': 'free', 'vendorID': 'EMC', 'capacity': '22548578304', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'initiatorname': 'default', 'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'password': '******', 'port': '3260'}], 'logicalblocksize': '512', 'pathstatus': [{'physdev': 'sdg', 'type': 'iSCSI', 'state': 'active', 'lun': '18'}], 'devtype': 'iSCSI', 'physicalblocksize': '512', 'pvUUID': 'aPJ9z2-Q7dz-KW6D-OrcG-69Us-omfE-lSKxRV', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs78_T5_LUN18_CKM00120100230', 'GUID': '36006048ce7ff8320bd02378f18cf9712', 'productID': 'Celerra'}, {'status': 'free', 'vendorID': 'EMC', 'capacity': '22548578304', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'initiatorname': 'default', 'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'password': '******', 'port': '3260'}], 'logicalblocksize': '512', 'pathstatus': [{'physdev': 'sdb', 'type': 'iSCSI', 'state': 'active', 'lun': '3'}], 'devtype': 'iSCSI', 'physicalblocksize': '512', 'pvUUID': 'e5YVTQ-0qeM-K75P-PsMv-wIRr-eeyO-mWkCoO', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs74_T5_LUN3_CKM00120100230', 'GUID': '36006048c78acaa6eac8ebc05bf73dee1', 'productID': 'Celerra'}, {'status': 'free', 'vendorID': 'EMC', 'capacity': '268435456000', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'initiatorname': 'default', 'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'password': '******', 'port': '3260'}], 'logicalblocksize': '512', 'pathstatus': [{'physdev': 'sdf', 'type': 'iSCSI', 'state': 'active', 'lun': '7'}], 'devtype': 'iSCSI', 'physicalblocksize': '512', 'pvUUID': 'xLNifQ-RGfE-zGdu-X1ti-u5Lh-sqoD-ERjjsU', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs62_T5_LUN7_CKM00120100230', 'GUID': '36006048c14e9eb8f668dfc53ea5995ca', 'productID': 'Celerra'}, {'status': 'free', 'vendorID': 'EMC', 'capacity': '22548578304', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'initiatorname': 'default', 'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'password': '******', 'port': '3260'}], 'logicalblocksize': '512', 'pathstatus': [{'physdev': 'sde', 'type': 'iSCSI', 'state': 'active', 'lun': '6'}], 'devtype': 'iSCSI', 'physicalblocksize': '512', 'pvUUID': 'RyIQ1E-OzCU-SRdk-GJgL-c792-eawC-bYqARi', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs77_T5_LUN6_CKM00120100230', 'GUID': '36006048c12952607a6254682d950135a', 'productID': 'Celerra'}, {'status': 'free', 'vendorID': 'EMC', 'capacity': '22548578304', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'initiatorname': 'default', 'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'password': '******', 'port': '3260'}], 'logicalblocksize': '512', 'pathstatus': [{'physdev': 'sdc', 'type': 'iSCSI', 'state': 'active', 'lun': '4'}], 'devtype': 'iSCSI', 'physicalblocksize': '512', 'pvUUID': 'cv45tO-w5Vv-mAxX-C2Ec-63Sq-uhYX-XcMeTz', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs75_T5_LUN4_CKM00120100230', 'GUID': '36006048c0714062ba4b91f6a904bc07f', 'productID': 'Celerra'}, {'status': 'free', 'vendorID': 'EMC', 'capacity': '22548578304', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'initiatorname': 'default', 'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'password': '******', 'port': '3260'}], 'logicalblocksize': '512', 'pathstatus': [{'physdev': 'sdd', 'type': 'iSCSI', 'state': 'active', 'lun': '5'}], 'devtype': 'iSCSI', 'physicalblocksize': '512', 'pvUUID': '', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs76_T5_LUN5_CKM00120100230', 'GUID': '36006048cc786b195adb3de2b6d613cbc', 'productID': 'Celerra'}, {'status': 'free', 'vendorID': 'RH-str02', 'capacity': '21474836480', 'fwrev': '0001', 'vgUUID': '', 'pathlist': [{'initiatorname': 'default', 'connection': '10.34.63.204', 'iqn': 'iqn.2012-09.brq.str-02:jlibosva', 'portal': '1', 'password': '******', 'port': '3260'}], 'logicalblocksize': '512', 'pathstatus': [{'physdev': 'sdh', 'type': 'iSCSI', 'state': 'active', 'lun': '1'}], 'devtype': 'iSCSI', 'physicalblocksize': '512', 'pvUUID': 'PCLUOA-wxBR-FLgk-SCM3-MenL-RYWf-qiqFwY', 'serial': 'SRH-str02VIRTUAL-DISK', 'GUID': '1jlibosva', 'productID': 'VIRTUAL-DISK'}, {'status': 'free', 'vendorID': 'RH-str01', 'capacity': '139586437120', 'fwrev': '0001', 'vgUUID': '', 'pathlist': [{'initiatorname': 'default', 'connection': '10.34.63.202', 'iqn': 'iqn.2011-01.brq.str-01:pstehlik', 'portal': '1', 'password': '******', 'port': '3260'}], 'logicalblocksize': '512', 'pathstatus': [{'physdev': 'sdi', 'type': 'iSCSI', 'state': 'active', 'lun': '1'}], 'devtype': 'iSCSI', 'physicalblocksize': '512', 'pvUUID': 'UJ1JCv-ejaX-95oi-A5bF-ZMHa-OGGj-kl11Ux', 'serial': 'SRH-str01VIRTUAL-DISK', 'GUID': '1ps01', 'productID': 'VIRTUAL-DISK'}, {'status': 'free', 'vendorID': 'RH-str01', 'capacity': '75161927680', 'fwrev': '0001', 'vgUUID': '', 'pathlist': [{'initiatorname': 'default', 'connection': '10.34.63.202', 'iqn': 'iqn.2011-01.brq.str-01:pstehlik', 'portal': '1', 'password': '******', 'port': '3260'}], 'logicalblocksize': '512', 'pathstatus': [{'physdev': 'sdj', 'type': 'iSCSI', 'state': 'active', 'lun': '2'}], 'devtype': 'iSCSI', 'physicalblocksize': '512', 'pvUUID': '7oLRYL-81F0-6vX3-ZIpd-cUj4-M440-di9F38', 'serial': 'SRH-str01VIRTUAL-DISK', 'GUID': '1ps02', 'productID': 'VIRTUAL-DISK'}, {'status': 'used', 'vendorID': 'RH-str01', 'capacity': '21474836480', 'fwrev': '0001', 'vgUUID': 'peP3zj-WQdO-wVEj-O6yX-YeRl-jIjq-5GnXoX', 'pathlist': [{'initiatorname': 'default', 'connection': '10.34.63.202', 'iqn': 'iqn.2011-01.brq.str-01:pstehlik', 'portal': '1', 'password': '******', 'port': '3260'}], 'logicalblocksize': '512', 'pathstatus': [{'physdev': 'sdk', 'type': 'iSCSI', 'state': 'active', 'lun': '3'}], 'devtype': 'iSCSI', 'physicalblocksize': '512', 'pvUUID': '1E6sAi-Sqj7-j1CD-gTin-22Fi-UTNt-i9r3nt', 'serial': 'SRH-str01VIRTUAL-DISK', 'GUID': '1pstehlik', 'productID': 'VIRTUAL-DISK'}]}
>Thread-142906::DEBUG::2012-09-26 15:30:53,810::task::1172::TaskManager.Task::(prepare) Task=`f36bab81-34ce-4ee7-921b-363b46374b37`::finished: {'devList': [{'status': 'free', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}], 'logicalblocksize': '512', 'devtype': 'iSCSI', 'physicalblocksize': '512', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs78_T5_LUN18_CKM00120100230', 'GUID': '36006048ce7ff8320bd02378f18cf9712', 'productID': 'Celerra', 'vendorID': 'EMC', 'capacity': '22548578304', 'pathstatus': [{'physdev': 'sdg', 'state': 'active', 'type': 'iSCSI', 'lun': '18'}], 'pvUUID': 'aPJ9z2-Q7dz-KW6D-OrcG-69Us-omfE-lSKxRV'}, {'status': 'free', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}], 'logicalblocksize': '512', 'devtype': 'iSCSI', 'physicalblocksize': '512', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs74_T5_LUN3_CKM00120100230', 'GUID': '36006048c78acaa6eac8ebc05bf73dee1', 'productID': 'Celerra', 'vendorID': 'EMC', 'capacity': '22548578304', 'pathstatus': [{'physdev': 'sdb', 'state': 'active', 'type': 'iSCSI', 'lun': '3'}], 'pvUUID': 'e5YVTQ-0qeM-K75P-PsMv-wIRr-eeyO-mWkCoO'}, {'status': 'free', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}], 'logicalblocksize': '512', 'devtype': 'iSCSI', 'physicalblocksize': '512', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs62_T5_LUN7_CKM00120100230', 'GUID': '36006048c14e9eb8f668dfc53ea5995ca', 'productID': 'Celerra', 'vendorID': 'EMC', 'capacity': '268435456000', 'pathstatus': [{'physdev': 'sdf', 'state': 'active', 'type': 'iSCSI', 'lun': '7'}], 'pvUUID': 'xLNifQ-RGfE-zGdu-X1ti-u5Lh-sqoD-ERjjsU'}, {'status': 'free', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}], 'logicalblocksize': '512', 'devtype': 'iSCSI', 'physicalblocksize': '512', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs77_T5_LUN6_CKM00120100230', 'GUID': '36006048c12952607a6254682d950135a', 'productID': 'Celerra', 'vendorID': 'EMC', 'capacity': '22548578304', 'pathstatus': [{'physdev': 'sde', 'state': 'active', 'type': 'iSCSI', 'lun': '6'}], 'pvUUID': 'RyIQ1E-OzCU-SRdk-GJgL-c792-eawC-bYqARi'}, {'status': 'free', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}], 'logicalblocksize': '512', 'devtype': 'iSCSI', 'physicalblocksize': '512', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs75_T5_LUN4_CKM00120100230', 'GUID': '36006048c0714062ba4b91f6a904bc07f', 'productID': 'Celerra', 'vendorID': 'EMC', 'capacity': '22548578304', 'pathstatus': [{'physdev': 'sdc', 'state': 'active', 'type': 'iSCSI', 'lun': '4'}], 'pvUUID': 'cv45tO-w5Vv-mAxX-C2Ec-63Sq-uhYX-XcMeTz'}, {'status': 'free', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}], 'logicalblocksize': '512', 'devtype': 'iSCSI', 'physicalblocksize': '512', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs76_T5_LUN5_CKM00120100230', 'GUID': '36006048cc786b195adb3de2b6d613cbc', 'productID': 'Celerra', 'vendorID': 'EMC', 'capacity': '22548578304', 'pathstatus': [{'physdev': 'sdd', 'state': 'active', 'type': 'iSCSI', 'lun': '5'}], 'pvUUID': ''}, {'status': 'free', 'fwrev': '0001', 'vgUUID': '', 'pathlist': [{'connection': '10.34.63.204', 'iqn': 'iqn.2012-09.brq.str-02:jlibosva', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}], 'logicalblocksize': '512', 'devtype': 'iSCSI', 'physicalblocksize': '512', 'serial': 'SRH-str02VIRTUAL-DISK', 'GUID': '1jlibosva', 'productID': 'VIRTUAL-DISK', 'vendorID': 'RH-str02', 'capacity': '21474836480', 'pathstatus': [{'physdev': 'sdh', 'state': 'active', 'type': 'iSCSI', 'lun': '1'}], 'pvUUID': 'PCLUOA-wxBR-FLgk-SCM3-MenL-RYWf-qiqFwY'}, {'status': 'free', 'fwrev': '0001', 'vgUUID': '', 'pathlist': [{'connection': '10.34.63.202', 'iqn': 'iqn.2011-01.brq.str-01:pstehlik', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}], 'logicalblocksize': '512', 'devtype': 'iSCSI', 'physicalblocksize': '512', 'serial': 'SRH-str01VIRTUAL-DISK', 'GUID': '1ps01', 'productID': 'VIRTUAL-DISK', 'vendorID': 'RH-str01', 'capacity': '139586437120', 'pathstatus': [{'physdev': 'sdi', 'state': 'active', 'type': 'iSCSI', 'lun': '1'}], 'pvUUID': 'UJ1JCv-ejaX-95oi-A5bF-ZMHa-OGGj-kl11Ux'}, {'status': 'free', 'fwrev': '0001', 'vgUUID': '', 'pathlist': [{'connection': '10.34.63.202', 'iqn': 'iqn.2011-01.brq.str-01:pstehlik', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}], 'logicalblocksize': '512', 'devtype': 'iSCSI', 'physicalblocksize': '512', 'serial': 'SRH-str01VIRTUAL-DISK', 'GUID': '1ps02', 'productID': 'VIRTUAL-DISK', 'vendorID': 'RH-str01', 'capacity': '75161927680', 'pathstatus': [{'physdev': 'sdj', 'state': 'active', 'type': 'iSCSI', 'lun': '2'}], 'pvUUID': '7oLRYL-81F0-6vX3-ZIpd-cUj4-M440-di9F38'}, {'status': 'used', 'fwrev': '0001', 'vgUUID': 'peP3zj-WQdO-wVEj-O6yX-YeRl-jIjq-5GnXoX', 'pathlist': [{'connection': '10.34.63.202', 'iqn': 'iqn.2011-01.brq.str-01:pstehlik', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}], 'logicalblocksize': '512', 'devtype': 'iSCSI', 'physicalblocksize': '512', 'serial': 'SRH-str01VIRTUAL-DISK', 'GUID': '1pstehlik', 'productID': 'VIRTUAL-DISK', 'vendorID': 'RH-str01', 'capacity': '21474836480', 'pathstatus': [{'physdev': 'sdk', 'state': 'active', 'type': 'iSCSI', 'lun': '3'}], 'pvUUID': '1E6sAi-Sqj7-j1CD-gTin-22Fi-UTNt-i9r3nt'}]}
>Thread-142906::DEBUG::2012-09-26 15:30:53,811::task::588::TaskManager.Task::(_updateState) Task=`f36bab81-34ce-4ee7-921b-363b46374b37`::moving from state preparing -> state finished
>Thread-142906::DEBUG::2012-09-26 15:30:53,812::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142906::DEBUG::2012-09-26 15:30:53,812::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142906::DEBUG::2012-09-26 15:30:53,813::task::978::TaskManager.Task::(_decref) Task=`f36bab81-34ce-4ee7-921b-363b46374b37`::ref 0 aborting False
>Thread-142909::DEBUG::2012-09-26 15:30:57,145::task::588::TaskManager.Task::(_updateState) Task=`08f8fcba-309b-4792-ae3d-d5dcb1f10bc9`::moving from state init -> state preparing
>Thread-142909::INFO::2012-09-26 15:30:57,146::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-142909::INFO::2012-09-26 15:30:57,146::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-142909::DEBUG::2012-09-26 15:30:57,147::task::1172::TaskManager.Task::(prepare) Task=`08f8fcba-309b-4792-ae3d-d5dcb1f10bc9`::finished: {}
>Thread-142909::DEBUG::2012-09-26 15:30:57,147::task::588::TaskManager.Task::(_updateState) Task=`08f8fcba-309b-4792-ae3d-d5dcb1f10bc9`::moving from state preparing -> state finished
>Thread-142909::DEBUG::2012-09-26 15:30:57,147::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142909::DEBUG::2012-09-26 15:30:57,148::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142909::DEBUG::2012-09-26 15:30:57,148::task::978::TaskManager.Task::(_decref) Task=`08f8fcba-309b-4792-ae3d-d5dcb1f10bc9`::ref 0 aborting False
>Thread-142915::DEBUG::2012-09-26 15:31:07,208::task::588::TaskManager.Task::(_updateState) Task=`ff0fba59-4446-4699-a35e-796e5224b1c2`::moving from state init -> state preparing
>Thread-142915::INFO::2012-09-26 15:31:07,208::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-142915::INFO::2012-09-26 15:31:07,209::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-142915::DEBUG::2012-09-26 15:31:07,209::task::1172::TaskManager.Task::(prepare) Task=`ff0fba59-4446-4699-a35e-796e5224b1c2`::finished: {}
>Thread-142915::DEBUG::2012-09-26 15:31:07,210::task::588::TaskManager.Task::(_updateState) Task=`ff0fba59-4446-4699-a35e-796e5224b1c2`::moving from state preparing -> state finished
>Thread-142915::DEBUG::2012-09-26 15:31:07,210::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142915::DEBUG::2012-09-26 15:31:07,210::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142915::DEBUG::2012-09-26 15:31:07,211::task::978::TaskManager.Task::(_decref) Task=`ff0fba59-4446-4699-a35e-796e5224b1c2`::ref 0 aborting False
>Thread-142921::DEBUG::2012-09-26 15:31:17,268::task::588::TaskManager.Task::(_updateState) Task=`a9a9ac8e-ceda-4e2d-bcbb-a70230e43328`::moving from state init -> state preparing
>Thread-142921::INFO::2012-09-26 15:31:17,268::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-142921::INFO::2012-09-26 15:31:17,269::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-142921::DEBUG::2012-09-26 15:31:17,269::task::1172::TaskManager.Task::(prepare) Task=`a9a9ac8e-ceda-4e2d-bcbb-a70230e43328`::finished: {}
>Thread-142921::DEBUG::2012-09-26 15:31:17,269::task::588::TaskManager.Task::(_updateState) Task=`a9a9ac8e-ceda-4e2d-bcbb-a70230e43328`::moving from state preparing -> state finished
>Thread-142921::DEBUG::2012-09-26 15:31:17,270::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142921::DEBUG::2012-09-26 15:31:17,270::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142921::DEBUG::2012-09-26 15:31:17,271::task::978::TaskManager.Task::(_decref) Task=`a9a9ac8e-ceda-4e2d-bcbb-a70230e43328`::ref 0 aborting False
>Thread-142927::DEBUG::2012-09-26 15:31:27,328::task::588::TaskManager.Task::(_updateState) Task=`513be50a-4a45-4d42-9592-62a08c58de7a`::moving from state init -> state preparing
>Thread-142927::INFO::2012-09-26 15:31:27,329::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-142927::INFO::2012-09-26 15:31:27,329::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-142927::DEBUG::2012-09-26 15:31:27,330::task::1172::TaskManager.Task::(prepare) Task=`513be50a-4a45-4d42-9592-62a08c58de7a`::finished: {}
>Thread-142927::DEBUG::2012-09-26 15:31:27,330::task::588::TaskManager.Task::(_updateState) Task=`513be50a-4a45-4d42-9592-62a08c58de7a`::moving from state preparing -> state finished
>Thread-142927::DEBUG::2012-09-26 15:31:27,331::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142927::DEBUG::2012-09-26 15:31:27,331::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142927::DEBUG::2012-09-26 15:31:27,332::task::978::TaskManager.Task::(_decref) Task=`513be50a-4a45-4d42-9592-62a08c58de7a`::ref 0 aborting False
>Thread-142933::DEBUG::2012-09-26 15:31:37,391::task::588::TaskManager.Task::(_updateState) Task=`9ecca204-b810-47f3-b427-5550fd18adec`::moving from state init -> state preparing
>Thread-142933::INFO::2012-09-26 15:31:37,392::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-142933::INFO::2012-09-26 15:31:37,392::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-142933::DEBUG::2012-09-26 15:31:37,393::task::1172::TaskManager.Task::(prepare) Task=`9ecca204-b810-47f3-b427-5550fd18adec`::finished: {}
>Thread-142933::DEBUG::2012-09-26 15:31:37,393::task::588::TaskManager.Task::(_updateState) Task=`9ecca204-b810-47f3-b427-5550fd18adec`::moving from state preparing -> state finished
>Thread-142933::DEBUG::2012-09-26 15:31:37,394::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142933::DEBUG::2012-09-26 15:31:37,394::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142933::DEBUG::2012-09-26 15:31:37,395::task::978::TaskManager.Task::(_decref) Task=`9ecca204-b810-47f3-b427-5550fd18adec`::ref 0 aborting False
>Thread-142939::DEBUG::2012-09-26 15:31:47,452::task::588::TaskManager.Task::(_updateState) Task=`50fa0cf2-224f-4cf9-bd80-35af7e6e3927`::moving from state init -> state preparing
>Thread-142939::INFO::2012-09-26 15:31:47,453::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-142939::INFO::2012-09-26 15:31:47,453::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-142939::DEBUG::2012-09-26 15:31:47,454::task::1172::TaskManager.Task::(prepare) Task=`50fa0cf2-224f-4cf9-bd80-35af7e6e3927`::finished: {}
>Thread-142939::DEBUG::2012-09-26 15:31:47,454::task::588::TaskManager.Task::(_updateState) Task=`50fa0cf2-224f-4cf9-bd80-35af7e6e3927`::moving from state preparing -> state finished
>Thread-142939::DEBUG::2012-09-26 15:31:47,454::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142939::DEBUG::2012-09-26 15:31:47,455::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142939::DEBUG::2012-09-26 15:31:47,455::task::978::TaskManager.Task::(_decref) Task=`50fa0cf2-224f-4cf9-bd80-35af7e6e3927`::ref 0 aborting False
>Thread-142945::DEBUG::2012-09-26 15:31:57,514::task::588::TaskManager.Task::(_updateState) Task=`ca9455f8-dc9c-4cbb-92f1-19a71c514f70`::moving from state init -> state preparing
>Thread-142945::INFO::2012-09-26 15:31:57,515::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-142945::INFO::2012-09-26 15:31:57,516::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-142945::DEBUG::2012-09-26 15:31:57,516::task::1172::TaskManager.Task::(prepare) Task=`ca9455f8-dc9c-4cbb-92f1-19a71c514f70`::finished: {}
>Thread-142945::DEBUG::2012-09-26 15:31:57,516::task::588::TaskManager.Task::(_updateState) Task=`ca9455f8-dc9c-4cbb-92f1-19a71c514f70`::moving from state preparing -> state finished
>Thread-142945::DEBUG::2012-09-26 15:31:57,517::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142945::DEBUG::2012-09-26 15:31:57,517::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142945::DEBUG::2012-09-26 15:31:57,518::task::978::TaskManager.Task::(_decref) Task=`ca9455f8-dc9c-4cbb-92f1-19a71c514f70`::ref 0 aborting False
>Thread-142951::DEBUG::2012-09-26 15:32:07,571::task::588::TaskManager.Task::(_updateState) Task=`b9c25ef0-3542-407e-aacc-d14c37c6bb76`::moving from state init -> state preparing
>Thread-142951::INFO::2012-09-26 15:32:07,572::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-142951::INFO::2012-09-26 15:32:07,572::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-142951::DEBUG::2012-09-26 15:32:07,573::task::1172::TaskManager.Task::(prepare) Task=`b9c25ef0-3542-407e-aacc-d14c37c6bb76`::finished: {}
>Thread-142951::DEBUG::2012-09-26 15:32:07,573::task::588::TaskManager.Task::(_updateState) Task=`b9c25ef0-3542-407e-aacc-d14c37c6bb76`::moving from state preparing -> state finished
>Thread-142951::DEBUG::2012-09-26 15:32:07,574::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142951::DEBUG::2012-09-26 15:32:07,574::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142951::DEBUG::2012-09-26 15:32:07,575::task::978::TaskManager.Task::(_decref) Task=`b9c25ef0-3542-407e-aacc-d14c37c6bb76`::ref 0 aborting False
>Thread-142957::DEBUG::2012-09-26 15:32:17,634::task::588::TaskManager.Task::(_updateState) Task=`2ec30866-a0e0-4618-966f-e14d827c06f4`::moving from state init -> state preparing
>Thread-142957::INFO::2012-09-26 15:32:17,634::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-142957::INFO::2012-09-26 15:32:17,635::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-142957::DEBUG::2012-09-26 15:32:17,635::task::1172::TaskManager.Task::(prepare) Task=`2ec30866-a0e0-4618-966f-e14d827c06f4`::finished: {}
>Thread-142957::DEBUG::2012-09-26 15:32:17,636::task::588::TaskManager.Task::(_updateState) Task=`2ec30866-a0e0-4618-966f-e14d827c06f4`::moving from state preparing -> state finished
>Thread-142957::DEBUG::2012-09-26 15:32:17,636::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142957::DEBUG::2012-09-26 15:32:17,637::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142957::DEBUG::2012-09-26 15:32:17,637::task::978::TaskManager.Task::(_decref) Task=`2ec30866-a0e0-4618-966f-e14d827c06f4`::ref 0 aborting False
>Thread-142963::DEBUG::2012-09-26 15:32:27,693::task::588::TaskManager.Task::(_updateState) Task=`2f0faee9-b7df-4e98-b84a-ff6ffec916bf`::moving from state init -> state preparing
>Thread-142963::INFO::2012-09-26 15:32:27,693::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-142963::INFO::2012-09-26 15:32:27,694::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-142963::DEBUG::2012-09-26 15:32:27,694::task::1172::TaskManager.Task::(prepare) Task=`2f0faee9-b7df-4e98-b84a-ff6ffec916bf`::finished: {}
>Thread-142963::DEBUG::2012-09-26 15:32:27,695::task::588::TaskManager.Task::(_updateState) Task=`2f0faee9-b7df-4e98-b84a-ff6ffec916bf`::moving from state preparing -> state finished
>Thread-142963::DEBUG::2012-09-26 15:32:27,695::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142963::DEBUG::2012-09-26 15:32:27,696::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142963::DEBUG::2012-09-26 15:32:27,696::task::978::TaskManager.Task::(_decref) Task=`2f0faee9-b7df-4e98-b84a-ff6ffec916bf`::ref 0 aborting False
>Thread-142969::DEBUG::2012-09-26 15:32:37,751::task::588::TaskManager.Task::(_updateState) Task=`a04f6e71-ee39-4948-8ac2-a9833c209b40`::moving from state init -> state preparing
>Thread-142969::INFO::2012-09-26 15:32:37,752::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-142969::INFO::2012-09-26 15:32:37,752::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-142969::DEBUG::2012-09-26 15:32:37,752::task::1172::TaskManager.Task::(prepare) Task=`a04f6e71-ee39-4948-8ac2-a9833c209b40`::finished: {}
>Thread-142969::DEBUG::2012-09-26 15:32:37,753::task::588::TaskManager.Task::(_updateState) Task=`a04f6e71-ee39-4948-8ac2-a9833c209b40`::moving from state preparing -> state finished
>Thread-142969::DEBUG::2012-09-26 15:32:37,753::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142969::DEBUG::2012-09-26 15:32:37,754::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142969::DEBUG::2012-09-26 15:32:37,754::task::978::TaskManager.Task::(_decref) Task=`a04f6e71-ee39-4948-8ac2-a9833c209b40`::ref 0 aborting False
>Thread-142975::DEBUG::2012-09-26 15:32:47,810::task::588::TaskManager.Task::(_updateState) Task=`1d0d59e4-2043-49b4-8379-ae5e0fdda921`::moving from state init -> state preparing
>Thread-142975::INFO::2012-09-26 15:32:47,811::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-142975::INFO::2012-09-26 15:32:47,812::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-142975::DEBUG::2012-09-26 15:32:47,812::task::1172::TaskManager.Task::(prepare) Task=`1d0d59e4-2043-49b4-8379-ae5e0fdda921`::finished: {}
>Thread-142975::DEBUG::2012-09-26 15:32:47,812::task::588::TaskManager.Task::(_updateState) Task=`1d0d59e4-2043-49b4-8379-ae5e0fdda921`::moving from state preparing -> state finished
>Thread-142975::DEBUG::2012-09-26 15:32:47,813::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142975::DEBUG::2012-09-26 15:32:47,813::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142975::DEBUG::2012-09-26 15:32:47,814::task::978::TaskManager.Task::(_decref) Task=`1d0d59e4-2043-49b4-8379-ae5e0fdda921`::ref 0 aborting False
>Thread-142978::DEBUG::2012-09-26 15:32:49,925::BindingXMLRPC::164::vds::(wrapper) [10.34.63.27]
>Thread-142978::DEBUG::2012-09-26 15:32:49,926::task::588::TaskManager.Task::(_updateState) Task=`a30a4b25-6ec1-47b4-b361-3b9830f9f6e3`::moving from state init -> state preparing
>Thread-142978::INFO::2012-09-26 15:32:49,926::logUtils::37::dispatcher::(wrapper) Run and protect: discoverSendTargets(con={'connection': '10.34.63.204', 'password': '******', 'port': '3260', 'user': ''}, options=None)
>Thread-142978::DEBUG::2012-09-26 15:32:49,927::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m discoverydb -t sendtargets -I default -p 10.34.63.204:3260 --op=new' (cwd None)
>Thread-142978::DEBUG::2012-09-26 15:32:49,956::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-142978::DEBUG::2012-09-26 15:32:49,957::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m discoverydb -t sendtargets -I default -p 10.34.63.204:3260 -n node.startup -v manual --op=update' (cwd None)
>Thread-142978::DEBUG::2012-09-26 15:32:49,985::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: Cannot modify node.startup. Invalid param name.\n'; <rc> = 7
>Thread-142978::DEBUG::2012-09-26 15:32:49,986::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m iface' (cwd None)
>Thread-142978::DEBUG::2012-09-26 15:32:50,016::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-142978::DEBUG::2012-09-26 15:32:50,017::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m discoverydb -t sendtargets -I default -p 10.34.63.204:3260 --discover' (cwd None)
>Thread-142978::DEBUG::2012-09-26 15:32:50,062::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-142978::DEBUG::2012-09-26 15:32:50,063::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m discoverydb -t sendtargets -I default -p 10.34.63.204:3260 --op=delete' (cwd None)
>Thread-142978::DEBUG::2012-09-26 15:32:50,096::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-142978::INFO::2012-09-26 15:32:50,097::logUtils::39::dispatcher::(wrapper) Run and protect: discoverSendTargets, Return response: {'fullTargets': ['10.34.63.204:3260,1 iqn.2011-02.brq.str-02:brqsetup02', '10.34.63.204:3260,1 iqn.2011-02.brq.str-02:lbednar', '10.34.63.204:3260,1 iqn.2011-02.brq.str-02:mpavlik', '10.34.63.204:3260,1 iqn.2011-01.brq.str-02:jhenner', '10.34.63.204:3260,1 iqn.2011-01.brq.str-02:pdufek', '10.34.63.204:3260,1 iqn.2011-01.brq.str-02:pstehlik', '10.34.63.204:3260,1 iqn.2011-01.brq.str-02:tdosek', '10.34.63.204:3260,1 iqn.2011-02.brq.str-02:adarazs', '10.34.63.204:3260,1 iqn.2011-02.brq.str-02:pnovotny', '10.34.63.204:3260,1 iqn.2011-02.brq.str-02:sheslem', '10.34.63.204:3260,1 iqn.2011-11.brq.str-02:lsvaty', '10.34.63.204:3260,1 iqn.2011-11.brq.str-02:psavelye', '10.34.63.204:3260,1 iqn.2012-09.brq.str-02:jlibosva'], 'targets': ['iqn.2011-02.brq.str-02:brqsetup02', 'iqn.2011-02.brq.str-02:lbednar', 'iqn.2011-02.brq.str-02:mpavlik', 'iqn.2011-01.brq.str-02:jhenner', 'iqn.2011-01.brq.str-02:pdufek', 'iqn.2011-01.brq.str-02:pstehlik', 'iqn.2011-01.brq.str-02:tdosek', 'iqn.2011-02.brq.str-02:adarazs', 'iqn.2011-02.brq.str-02:pnovotny', 'iqn.2011-02.brq.str-02:sheslem', 'iqn.2011-11.brq.str-02:lsvaty', 'iqn.2011-11.brq.str-02:psavelye', 'iqn.2012-09.brq.str-02:jlibosva']}
>Thread-142978::DEBUG::2012-09-26 15:32:50,097::task::1172::TaskManager.Task::(prepare) Task=`a30a4b25-6ec1-47b4-b361-3b9830f9f6e3`::finished: {'fullTargets': ['10.34.63.204:3260,1 iqn.2011-02.brq.str-02:brqsetup02', '10.34.63.204:3260,1 iqn.2011-02.brq.str-02:lbednar', '10.34.63.204:3260,1 iqn.2011-02.brq.str-02:mpavlik', '10.34.63.204:3260,1 iqn.2011-01.brq.str-02:jhenner', '10.34.63.204:3260,1 iqn.2011-01.brq.str-02:pdufek', '10.34.63.204:3260,1 iqn.2011-01.brq.str-02:pstehlik', '10.34.63.204:3260,1 iqn.2011-01.brq.str-02:tdosek', '10.34.63.204:3260,1 iqn.2011-02.brq.str-02:adarazs', '10.34.63.204:3260,1 iqn.2011-02.brq.str-02:pnovotny', '10.34.63.204:3260,1 iqn.2011-02.brq.str-02:sheslem', '10.34.63.204:3260,1 iqn.2011-11.brq.str-02:lsvaty', '10.34.63.204:3260,1 iqn.2011-11.brq.str-02:psavelye', '10.34.63.204:3260,1 iqn.2012-09.brq.str-02:jlibosva'], 'targets': ['iqn.2011-02.brq.str-02:brqsetup02', 'iqn.2011-02.brq.str-02:lbednar', 'iqn.2011-02.brq.str-02:mpavlik', 'iqn.2011-01.brq.str-02:jhenner', 'iqn.2011-01.brq.str-02:pdufek', 'iqn.2011-01.brq.str-02:pstehlik', 'iqn.2011-01.brq.str-02:tdosek', 'iqn.2011-02.brq.str-02:adarazs', 'iqn.2011-02.brq.str-02:pnovotny', 'iqn.2011-02.brq.str-02:sheslem', 'iqn.2011-11.brq.str-02:lsvaty', 'iqn.2011-11.brq.str-02:psavelye', 'iqn.2012-09.brq.str-02:jlibosva']}
>Thread-142978::DEBUG::2012-09-26 15:32:50,098::task::588::TaskManager.Task::(_updateState) Task=`a30a4b25-6ec1-47b4-b361-3b9830f9f6e3`::moving from state preparing -> state finished
>Thread-142978::DEBUG::2012-09-26 15:32:50,098::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142978::DEBUG::2012-09-26 15:32:50,099::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142978::DEBUG::2012-09-26 15:32:50,099::task::978::TaskManager.Task::(_decref) Task=`a30a4b25-6ec1-47b4-b361-3b9830f9f6e3`::ref 0 aborting False
>Thread-142982::DEBUG::2012-09-26 15:32:57,870::task::588::TaskManager.Task::(_updateState) Task=`997b1047-8e0c-4360-a20b-627e3bd081e1`::moving from state init -> state preparing
>Thread-142982::INFO::2012-09-26 15:32:57,871::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-142982::INFO::2012-09-26 15:32:57,872::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-142982::DEBUG::2012-09-26 15:32:57,872::task::1172::TaskManager.Task::(prepare) Task=`997b1047-8e0c-4360-a20b-627e3bd081e1`::finished: {}
>Thread-142982::DEBUG::2012-09-26 15:32:57,873::task::588::TaskManager.Task::(_updateState) Task=`997b1047-8e0c-4360-a20b-627e3bd081e1`::moving from state preparing -> state finished
>Thread-142982::DEBUG::2012-09-26 15:32:57,874::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142982::DEBUG::2012-09-26 15:32:57,874::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142982::DEBUG::2012-09-26 15:32:57,875::task::978::TaskManager.Task::(_decref) Task=`997b1047-8e0c-4360-a20b-627e3bd081e1`::ref 0 aborting False
>Thread-142988::DEBUG::2012-09-26 15:33:07,933::task::588::TaskManager.Task::(_updateState) Task=`24b84cd7-c8da-45ab-bf62-81618bd64085`::moving from state init -> state preparing
>Thread-142988::INFO::2012-09-26 15:33:07,933::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-142988::INFO::2012-09-26 15:33:07,934::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-142988::DEBUG::2012-09-26 15:33:07,934::task::1172::TaskManager.Task::(prepare) Task=`24b84cd7-c8da-45ab-bf62-81618bd64085`::finished: {}
>Thread-142988::DEBUG::2012-09-26 15:33:07,934::task::588::TaskManager.Task::(_updateState) Task=`24b84cd7-c8da-45ab-bf62-81618bd64085`::moving from state preparing -> state finished
>Thread-142988::DEBUG::2012-09-26 15:33:07,935::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142988::DEBUG::2012-09-26 15:33:07,935::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142988::DEBUG::2012-09-26 15:33:07,936::task::978::TaskManager.Task::(_decref) Task=`24b84cd7-c8da-45ab-bf62-81618bd64085`::ref 0 aborting False
>Thread-142994::DEBUG::2012-09-26 15:33:17,994::task::588::TaskManager.Task::(_updateState) Task=`c1cf1287-8bae-4265-ad9a-2e4a8a84e94b`::moving from state init -> state preparing
>Thread-142994::INFO::2012-09-26 15:33:17,994::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-142994::INFO::2012-09-26 15:33:17,995::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-142994::DEBUG::2012-09-26 15:33:17,995::task::1172::TaskManager.Task::(prepare) Task=`c1cf1287-8bae-4265-ad9a-2e4a8a84e94b`::finished: {}
>Thread-142994::DEBUG::2012-09-26 15:33:17,996::task::588::TaskManager.Task::(_updateState) Task=`c1cf1287-8bae-4265-ad9a-2e4a8a84e94b`::moving from state preparing -> state finished
>Thread-142994::DEBUG::2012-09-26 15:33:17,996::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142994::DEBUG::2012-09-26 15:33:17,996::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142994::DEBUG::2012-09-26 15:33:17,997::task::978::TaskManager.Task::(_decref) Task=`c1cf1287-8bae-4265-ad9a-2e4a8a84e94b`::ref 0 aborting False
>Thread-142997::DEBUG::2012-09-26 15:33:22,020::BindingXMLRPC::164::vds::(wrapper) [10.34.63.27]
>Thread-142997::DEBUG::2012-09-26 15:33:22,020::task::588::TaskManager.Task::(_updateState) Task=`e20d5092-9e84-4c5f-bb01-5c8cb4e69c52`::moving from state init -> state preparing
>Thread-142997::INFO::2012-09-26 15:33:22,021::logUtils::37::dispatcher::(wrapper) Run and protect: validateStorageServerConnection(domType=3, spUUID='00000000-0000-0000-0000-000000000000', conList=[{'connection': '10.34.63.204', 'iqn': 'iqn.2011-01.brq.str-02:pstehlik', 'portal': '0', 'user': '', 'password': '******', 'id': '00000000-0000-0000-0000-000000000000', 'port': '3260'}], options=None)
>Thread-142997::INFO::2012-09-26 15:33:22,021::logUtils::39::dispatcher::(wrapper) Run and protect: validateStorageServerConnection, Return response: {'statuslist': [{'status': 0, 'id': '00000000-0000-0000-0000-000000000000'}]}
>Thread-142997::DEBUG::2012-09-26 15:33:22,022::task::1172::TaskManager.Task::(prepare) Task=`e20d5092-9e84-4c5f-bb01-5c8cb4e69c52`::finished: {'statuslist': [{'status': 0, 'id': '00000000-0000-0000-0000-000000000000'}]}
>Thread-142997::DEBUG::2012-09-26 15:33:22,022::task::588::TaskManager.Task::(_updateState) Task=`e20d5092-9e84-4c5f-bb01-5c8cb4e69c52`::moving from state preparing -> state finished
>Thread-142997::DEBUG::2012-09-26 15:33:22,023::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142997::DEBUG::2012-09-26 15:33:22,023::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142997::DEBUG::2012-09-26 15:33:22,023::task::978::TaskManager.Task::(_decref) Task=`e20d5092-9e84-4c5f-bb01-5c8cb4e69c52`::ref 0 aborting False
>Thread-142999::DEBUG::2012-09-26 15:33:22,045::BindingXMLRPC::164::vds::(wrapper) [10.34.63.27]
>Thread-142999::DEBUG::2012-09-26 15:33:22,046::task::588::TaskManager.Task::(_updateState) Task=`6ccf0c76-dc1b-4df2-be29-485827161225`::moving from state init -> state preparing
>Thread-142999::INFO::2012-09-26 15:33:22,046::logUtils::37::dispatcher::(wrapper) Run and protect: connectStorageServer(domType=3, spUUID='00000000-0000-0000-0000-000000000000', conList=[{'connection': '10.34.63.204', 'iqn': 'iqn.2011-01.brq.str-02:pstehlik', 'portal': '0', 'user': '', 'password': '******', 'id': '00000000-0000-0000-0000-000000000000', 'port': '3260'}], options=None)
>Thread-142999::DEBUG::2012-09-26 15:33:22,047::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2011-01.brq.str-02:pstehlik -I default -p 10.34.63.204:3260 --op=new' (cwd None)
>Thread-142999::DEBUG::2012-09-26 15:33:22,077::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-142999::DEBUG::2012-09-26 15:33:22,078::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2011-01.brq.str-02:pstehlik -I default -p 10.34.63.204:3260 -l' (cwd None)
>Thread-142999::DEBUG::2012-09-26 15:33:22,639::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-142999::DEBUG::2012-09-26 15:33:22,640::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2011-01.brq.str-02:pstehlik -I default -p 10.34.63.204:3260 -n node.startup -v manual --op=update' (cwd None)
>Thread-142999::DEBUG::2012-09-26 15:33:22,673::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-142999::DEBUG::2012-09-26 15:33:22,674::lvm::460::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-142999::DEBUG::2012-09-26 15:33:22,675::lvm::462::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-142999::DEBUG::2012-09-26 15:33:22,675::lvm::472::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-142999::DEBUG::2012-09-26 15:33:22,676::lvm::474::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-142999::DEBUG::2012-09-26 15:33:22,676::lvm::493::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-142999::DEBUG::2012-09-26 15:33:22,677::lvm::495::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-142999::INFO::2012-09-26 15:33:22,678::logUtils::39::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {'statuslist': [{'status': 0, 'id': '00000000-0000-0000-0000-000000000000'}]}
>Thread-142999::DEBUG::2012-09-26 15:33:22,678::task::1172::TaskManager.Task::(prepare) Task=`6ccf0c76-dc1b-4df2-be29-485827161225`::finished: {'statuslist': [{'status': 0, 'id': '00000000-0000-0000-0000-000000000000'}]}
>Thread-142999::DEBUG::2012-09-26 15:33:22,679::task::588::TaskManager.Task::(_updateState) Task=`6ccf0c76-dc1b-4df2-be29-485827161225`::moving from state preparing -> state finished
>Thread-142999::DEBUG::2012-09-26 15:33:22,679::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-142999::DEBUG::2012-09-26 15:33:22,679::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-142999::DEBUG::2012-09-26 15:33:22,687::task::978::TaskManager.Task::(_decref) Task=`6ccf0c76-dc1b-4df2-be29-485827161225`::ref 0 aborting False
>Thread-143000::DEBUG::2012-09-26 15:33:22,811::BindingXMLRPC::164::vds::(wrapper) [10.34.63.27]
>Thread-143000::DEBUG::2012-09-26 15:33:22,812::task::588::TaskManager.Task::(_updateState) Task=`04413442-9a14-4acb-8b54-dbd2087fca82`::moving from state init -> state preparing
>Thread-143000::INFO::2012-09-26 15:33:22,813::logUtils::37::dispatcher::(wrapper) Run and protect: getDeviceList(storageType=3, options={})
>Thread-143000::DEBUG::2012-09-26 15:33:22,813::misc::1080::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
>Thread-143000::DEBUG::2012-09-26 15:33:22,814::misc::1082::SamplingMethod::(__call__) Got in to sampling method
>Thread-143000::DEBUG::2012-09-26 15:33:22,814::misc::1080::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
>Thread-143000::DEBUG::2012-09-26 15:33:22,815::misc::1082::SamplingMethod::(__call__) Got in to sampling method
>Thread-143000::DEBUG::2012-09-26 15:33:22,815::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
>Thread-143000::DEBUG::2012-09-26 15:33:22,883::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-143000::DEBUG::2012-09-26 15:33:22,884::misc::1090::SamplingMethod::(__call__) Returning last result
>Thread-143000::DEBUG::2012-09-26 15:33:23,500::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None)
>Thread-143000::DEBUG::2012-09-26 15:33:23,718::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-143000::DEBUG::2012-09-26 15:33:23,719::lvm::460::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-143000::DEBUG::2012-09-26 15:33:23,719::lvm::462::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-143000::DEBUG::2012-09-26 15:33:23,720::lvm::472::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-143000::DEBUG::2012-09-26 15:33:23,720::lvm::474::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-143000::DEBUG::2012-09-26 15:33:23,721::lvm::493::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-143000::DEBUG::2012-09-26 15:33:23,721::lvm::495::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-143000::DEBUG::2012-09-26 15:33:23,722::misc::1090::SamplingMethod::(__call__) Returning last result
>Thread-143000::DEBUG::2012-09-26 15:33:23,723::lvm::319::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex
>Thread-143000::DEBUG::2012-09-26 15:33:23,727::__init__::1164::Storage.Misc.excCmd::(_log) '/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 = [ \\"a%1jlibosva|1ps01|1ps02|1pstehlik|36006048c0714062ba4b91f6a904bc07f|36006048c12952607a6254682d950135a|36006048c14e9eb8f668dfc53ea5995ca|36006048c78acaa6eac8ebc05bf73dee1|36006048cc786b195adb3de2b6d613cbc|36006048ce7ff8320bd02378f18cf9712%\\", \\"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)
>Thread-143000::DEBUG::2012-09-26 15:33:24,068::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  /dev/mapper/1pstehlik: lseek 117977382912 failed: Invalid argument\n  /dev/mapper/1pstehlik: lseek 117977382912 failed: Invalid argument\n  WARNING: Volume Group e82a647b-2bbb-490c-8139-15a1fd4937df is not consistent\n'; <rc> = 0
>Thread-143000::DEBUG::2012-09-26 15:33:24,069::lvm::342::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,070::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/dmsetup status' (cwd None)
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,076::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,082::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/scsi_id --page=0x80 --whitelisted --export --replace-whitespace --device=/dev/dm-3' (cwd None)
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,087::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,091::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/scsi_id --page=0x80 --whitelisted --export --replace-whitespace --device=/dev/dm-4' (cwd None)
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,095::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,098::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/scsi_id --page=0x80 --whitelisted --export --replace-whitespace --device=/dev/dm-5' (cwd None)
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,102::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,105::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/scsi_id --page=0x80 --whitelisted --export --replace-whitespace --device=/dev/dm-6' (cwd None)
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,109::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,112::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/scsi_id --page=0x80 --whitelisted --export --replace-whitespace --device=/dev/dm-7' (cwd None)
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,117::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,120::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/scsi_id --page=0x80 --whitelisted --export --replace-whitespace --device=/dev/dm-8' (cwd None)
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,124::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,127::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/scsi_id --page=0x80 --whitelisted --export --replace-whitespace --device=/dev/dm-9' (cwd None)
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,131::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,135::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/scsi_id --page=0x80 --whitelisted --export --replace-whitespace --device=/dev/dm-10' (cwd None)
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,139::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,143::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/scsi_id --page=0x80 --whitelisted --export --replace-whitespace --device=/dev/dm-11' (cwd None)
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,147::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,150::__init__::1164::Storage.Misc.excCmd::(_log) '/sbin/scsi_id --page=0x80 --whitelisted --export --replace-whitespace --device=/dev/dm-12' (cwd None)
>MainProcess|Thread-143000::DEBUG::2012-09-26 15:33:24,153::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = ''; <rc> = 1
>Thread-143000::DEBUG::2012-09-26 15:33:24,158::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm pvcreate --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"a%1jlibosva|1ps01|1ps02|1pstehlik|36006048c0714062ba4b91f6a904bc07f|36006048c12952607a6254682d950135a|36006048c14e9eb8f668dfc53ea5995ca|36006048c78acaa6eac8ebc05bf73dee1|36006048cc786b195adb3de2b6d613cbc|36006048ce7ff8320bd02378f18cf9712%\\", \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --test --metadatasize 128m --metadatacopies 2 --metadataignore y /dev/mapper/36006048ce7ff8320bd02378f18cf9712 /dev/mapper/36006048c78acaa6eac8ebc05bf73dee1 /dev/mapper/36006048c14e9eb8f668dfc53ea5995ca /dev/mapper/36006048c12952607a6254682d950135a /dev/mapper/36006048c0714062ba4b91f6a904bc07f /dev/mapper/36006048cc786b195adb3de2b6d613cbc /dev/mapper/1jlibosva /dev/mapper/1ps01 /dev/mapper/1ps02 /dev/mapper/1pstehlik' (cwd None)
>Thread-143000::DEBUG::2012-09-26 15:33:25,227::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = '  /dev/mapper/1pstehlik: lseek 117977382912 failed: Invalid argument\n  Writing physical volume data to disk "/dev/mapper/36006048ce7ff8320bd02378f18cf9712"\n  Writing physical volume data to disk "/dev/mapper/36006048c78acaa6eac8ebc05bf73dee1"\n  Writing physical volume data to disk "/dev/mapper/36006048c14e9eb8f668dfc53ea5995ca"\n  Writing physical volume data to disk "/dev/mapper/36006048c12952607a6254682d950135a"\n  Writing physical volume data to disk "/dev/mapper/36006048c0714062ba4b91f6a904bc07f"\n  Writing physical volume data to disk "/dev/mapper/36006048cc786b195adb3de2b6d613cbc"\n  Writing physical volume data to disk "/dev/mapper/1jlibosva"\n  Writing physical volume data to disk "/dev/mapper/1ps01"\n  Writing physical volume data to disk "/dev/mapper/1ps02"\n  /dev/mapper/1pstehlik: lseek 117977382912 failed: Invalid argument\n  WARNING: Volume group e82a647b-2bbb-490c-8139-15a1fd4937df is not consistent\n  Can\'t initialize physical volume "/dev/mapper/1pstehlik" of volume group "e82a647b-2bbb-490c-8139-15a1fd4937df" without -ff\n'; <rc> = 5
>Thread-143000::DEBUG::2012-09-26 15:33:25,230::lvm::751::Storage.LVM::(testPVCreate) rc: 5, out: ['  Test mode: Metadata will NOT be updated and volumes will not be (de)activated.', '  Physical volume "/dev/mapper/36006048ce7ff8320bd02378f18cf9712" successfully created', '  Physical volume "/dev/mapper/36006048c78acaa6eac8ebc05bf73dee1" successfully created', '  Physical volume "/dev/mapper/36006048c14e9eb8f668dfc53ea5995ca" successfully created', '  Physical volume "/dev/mapper/36006048c12952607a6254682d950135a" successfully created', '  Physical volume "/dev/mapper/36006048c0714062ba4b91f6a904bc07f" successfully created', '  Physical volume "/dev/mapper/36006048cc786b195adb3de2b6d613cbc" successfully created', '  Physical volume "/dev/mapper/1jlibosva" successfully created', '  Physical volume "/dev/mapper/1ps01" successfully created', '  Physical volume "/dev/mapper/1ps02" successfully created'], err: ['  /dev/mapper/1pstehlik: lseek 117977382912 failed: Invalid argument', '  Writing physical volume data to disk "/dev/mapper/36006048ce7ff8320bd02378f18cf9712"', '  Writing physical volume data to disk "/dev/mapper/36006048c78acaa6eac8ebc05bf73dee1"', '  Writing physical volume data to disk "/dev/mapper/36006048c14e9eb8f668dfc53ea5995ca"', '  Writing physical volume data to disk "/dev/mapper/36006048c12952607a6254682d950135a"', '  Writing physical volume data to disk "/dev/mapper/36006048c0714062ba4b91f6a904bc07f"', '  Writing physical volume data to disk "/dev/mapper/36006048cc786b195adb3de2b6d613cbc"', '  Writing physical volume data to disk "/dev/mapper/1jlibosva"', '  Writing physical volume data to disk "/dev/mapper/1ps01"', '  Writing physical volume data to disk "/dev/mapper/1ps02"', '  /dev/mapper/1pstehlik: lseek 117977382912 failed: Invalid argument', '  WARNING: Volume group e82a647b-2bbb-490c-8139-15a1fd4937df is not consistent', '  Can\'t initialize physical volume "/dev/mapper/1pstehlik" of volume group "e82a647b-2bbb-490c-8139-15a1fd4937df" without -ff'], unusedDevs: set(['/dev/mapper/1jlibosva', '/dev/mapper/36006048c14e9eb8f668dfc53ea5995ca', '/dev/mapper/36006048c0714062ba4b91f6a904bc07f', '/dev/mapper/1ps02', '/dev/mapper/36006048c12952607a6254682d950135a', '/dev/mapper/1ps01', '/dev/mapper/36006048cc786b195adb3de2b6d613cbc', '/dev/mapper/36006048ce7ff8320bd02378f18cf9712', '/dev/mapper/36006048c78acaa6eac8ebc05bf73dee1']), usedDevs: set(['/dev/mapper/1pstehlik'])
>Thread-143000::INFO::2012-09-26 15:33:25,232::logUtils::39::dispatcher::(wrapper) Run and protect: getDeviceList, Return response: {'devList': [{'status': 'free', 'vendorID': 'EMC', 'capacity': '22548578304', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'initiatorname': 'default', 'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'password': '******', 'port': '3260'}], 'logicalblocksize': '512', 'pathstatus': [{'physdev': 'sdg', 'type': 'iSCSI', 'state': 'active', 'lun': '18'}], 'devtype': 'iSCSI', 'physicalblocksize': '512', 'pvUUID': 'aPJ9z2-Q7dz-KW6D-OrcG-69Us-omfE-lSKxRV', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs78_T5_LUN18_CKM00120100230', 'GUID': '36006048ce7ff8320bd02378f18cf9712', 'productID': 'Celerra'}, {'status': 'free', 'vendorID': 'EMC', 'capacity': '22548578304', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'initiatorname': 'default', 'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'password': '******', 'port': '3260'}], 'logicalblocksize': '512', 'pathstatus': [{'physdev': 'sdb', 'type': 'iSCSI', 'state': 'active', 'lun': '3'}], 'devtype': 'iSCSI', 'physicalblocksize': '512', 'pvUUID': 'e5YVTQ-0qeM-K75P-PsMv-wIRr-eeyO-mWkCoO', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs74_T5_LUN3_CKM00120100230', 'GUID': '36006048c78acaa6eac8ebc05bf73dee1', 'productID': 'Celerra'}, {'status': 'free', 'vendorID': 'EMC', 'capacity': '268435456000', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'initiatorname': 'default', 'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'password': '******', 'port': '3260'}], 'logicalblocksize': '512', 'pathstatus': [{'physdev': 'sdf', 'type': 'iSCSI', 'state': 'active', 'lun': '7'}], 'devtype': 'iSCSI', 'physicalblocksize': '512', 'pvUUID': 'xLNifQ-RGfE-zGdu-X1ti-u5Lh-sqoD-ERjjsU', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs62_T5_LUN7_CKM00120100230', 'GUID': '36006048c14e9eb8f668dfc53ea5995ca', 'productID': 'Celerra'}, {'status': 'free', 'vendorID': 'EMC', 'capacity': '22548578304', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'initiatorname': 'default', 'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'password': '******', 'port': '3260'}], 'logicalblocksize': '512', 'pathstatus': [{'physdev': 'sde', 'type': 'iSCSI', 'state': 'active', 'lun': '6'}], 'devtype': 'iSCSI', 'physicalblocksize': '512', 'pvUUID': 'RyIQ1E-OzCU-SRdk-GJgL-c792-eawC-bYqARi', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs77_T5_LUN6_CKM00120100230', 'GUID': '36006048c12952607a6254682d950135a', 'productID': 'Celerra'}, {'status': 'free', 'vendorID': 'EMC', 'capacity': '22548578304', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'initiatorname': 'default', 'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'password': '******', 'port': '3260'}], 'logicalblocksize': '512', 'pathstatus': [{'physdev': 'sdc', 'type': 'iSCSI', 'state': 'active', 'lun': '4'}], 'devtype': 'iSCSI', 'physicalblocksize': '512', 'pvUUID': 'cv45tO-w5Vv-mAxX-C2Ec-63Sq-uhYX-XcMeTz', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs75_T5_LUN4_CKM00120100230', 'GUID': '36006048c0714062ba4b91f6a904bc07f', 'productID': 'Celerra'}, {'status': 'free', 'vendorID': 'EMC', 'capacity': '22548578304', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'initiatorname': 'default', 'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'password': '******', 'port': '3260'}], 'logicalblocksize': '512', 'pathstatus': [{'physdev': 'sdd', 'type': 'iSCSI', 'state': 'active', 'lun': '5'}], 'devtype': 'iSCSI', 'physicalblocksize': '512', 'pvUUID': '', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs76_T5_LUN5_CKM00120100230', 'GUID': '36006048cc786b195adb3de2b6d613cbc', 'productID': 'Celerra'}, {'status': 'free', 'vendorID': 'RH-str02', 'capacity': '21474836480', 'fwrev': '0001', 'vgUUID': '', 'pathlist': [{'initiatorname': 'default', 'connection': '10.34.63.204', 'iqn': 'iqn.2012-09.brq.str-02:jlibosva', 'portal': '1', 'password': '******', 'port': '3260'}], 'logicalblocksize': '512', 'pathstatus': [{'physdev': 'sdh', 'type': 'iSCSI', 'state': 'active', 'lun': '1'}], 'devtype': 'iSCSI', 'physicalblocksize': '512', 'pvUUID': 'PCLUOA-wxBR-FLgk-SCM3-MenL-RYWf-qiqFwY', 'serial': 'SRH-str02VIRTUAL-DISK', 'GUID': '1jlibosva', 'productID': 'VIRTUAL-DISK'}, {'status': 'free', 'vendorID': 'RH-str01', 'capacity': '139586437120', 'fwrev': '0001', 'vgUUID': '', 'pathlist': [{'initiatorname': 'default', 'connection': '10.34.63.202', 'iqn': 'iqn.2011-01.brq.str-01:pstehlik', 'portal': '1', 'password': '******', 'port': '3260'}], 'logicalblocksize': '512', 'pathstatus': [{'physdev': 'sdi', 'type': 'iSCSI', 'state': 'active', 'lun': '1'}], 'devtype': 'iSCSI', 'physicalblocksize': '512', 'pvUUID': 'UJ1JCv-ejaX-95oi-A5bF-ZMHa-OGGj-kl11Ux', 'serial': 'SRH-str01VIRTUAL-DISK', 'GUID': '1ps01', 'productID': 'VIRTUAL-DISK'}, {'status': 'free', 'vendorID': 'RH-str01', 'capacity': '75161927680', 'fwrev': '0001', 'vgUUID': '', 'pathlist': [{'initiatorname': 'default', 'connection': '10.34.63.202', 'iqn': 'iqn.2011-01.brq.str-01:pstehlik', 'portal': '1', 'password': '******', 'port': '3260'}], 'logicalblocksize': '512', 'pathstatus': [{'physdev': 'sdj', 'type': 'iSCSI', 'state': 'active', 'lun': '2'}], 'devtype': 'iSCSI', 'physicalblocksize': '512', 'pvUUID': '7oLRYL-81F0-6vX3-ZIpd-cUj4-M440-di9F38', 'serial': 'SRH-str01VIRTUAL-DISK', 'GUID': '1ps02', 'productID': 'VIRTUAL-DISK'}, {'status': 'used', 'vendorID': 'RH-str01', 'capacity': '21474836480', 'fwrev': '0001', 'vgUUID': 'cIvOog-TzN3-BwbK-jXTV-Y07B-mAYt-FahR5H', 'pathlist': [{'initiatorname': 'default', 'connection': '10.34.63.202', 'iqn': 'iqn.2011-01.brq.str-01:pstehlik', 'portal': '1', 'password': '******', 'port': '3260'}, {'initiatorname': 'default', 'connection': '10.34.63.204', 'iqn': 'iqn.2011-01.brq.str-02:pstehlik', 'portal': '1', 'password': '******', 'port': '3260'}], 'logicalblocksize': '512', 'pathstatus': [{'physdev': 'sdk', 'type': 'iSCSI', 'state': 'active', 'lun': '3'}, {'physdev': 'sdl', 'type': 'iSCSI', 'state': 'active', 'lun': '1'}], 'devtype': 'iSCSI', 'physicalblocksize': '512', 'pvUUID': 'tjWwz9-i4KV-3wjt-PUn5-fGbe-zX6c-IYtCuj', 'serial': '', 'GUID': '1pstehlik', 'productID': 'VIRTUAL-DISK'}]}
>Thread-143000::DEBUG::2012-09-26 15:33:25,233::task::1172::TaskManager.Task::(prepare) Task=`04413442-9a14-4acb-8b54-dbd2087fca82`::finished: {'devList': [{'status': 'free', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}], 'logicalblocksize': '512', 'devtype': 'iSCSI', 'physicalblocksize': '512', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs78_T5_LUN18_CKM00120100230', 'GUID': '36006048ce7ff8320bd02378f18cf9712', 'productID': 'Celerra', 'vendorID': 'EMC', 'capacity': '22548578304', 'pathstatus': [{'physdev': 'sdg', 'state': 'active', 'type': 'iSCSI', 'lun': '18'}], 'pvUUID': 'aPJ9z2-Q7dz-KW6D-OrcG-69Us-omfE-lSKxRV'}, {'status': 'free', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}], 'logicalblocksize': '512', 'devtype': 'iSCSI', 'physicalblocksize': '512', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs74_T5_LUN3_CKM00120100230', 'GUID': '36006048c78acaa6eac8ebc05bf73dee1', 'productID': 'Celerra', 'vendorID': 'EMC', 'capacity': '22548578304', 'pathstatus': [{'physdev': 'sdb', 'state': 'active', 'type': 'iSCSI', 'lun': '3'}], 'pvUUID': 'e5YVTQ-0qeM-K75P-PsMv-wIRr-eeyO-mWkCoO'}, {'status': 'free', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}], 'logicalblocksize': '512', 'devtype': 'iSCSI', 'physicalblocksize': '512', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs62_T5_LUN7_CKM00120100230', 'GUID': '36006048c14e9eb8f668dfc53ea5995ca', 'productID': 'Celerra', 'vendorID': 'EMC', 'capacity': '268435456000', 'pathstatus': [{'physdev': 'sdf', 'state': 'active', 'type': 'iSCSI', 'lun': '7'}], 'pvUUID': 'xLNifQ-RGfE-zGdu-X1ti-u5Lh-sqoD-ERjjsU'}, {'status': 'free', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}], 'logicalblocksize': '512', 'devtype': 'iSCSI', 'physicalblocksize': '512', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs77_T5_LUN6_CKM00120100230', 'GUID': '36006048c12952607a6254682d950135a', 'productID': 'Celerra', 'vendorID': 'EMC', 'capacity': '22548578304', 'pathstatus': [{'physdev': 'sde', 'state': 'active', 'type': 'iSCSI', 'lun': '6'}], 'pvUUID': 'RyIQ1E-OzCU-SRdk-GJgL-c792-eawC-bYqARi'}, {'status': 'free', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}], 'logicalblocksize': '512', 'devtype': 'iSCSI', 'physicalblocksize': '512', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs75_T5_LUN4_CKM00120100230', 'GUID': '36006048c0714062ba4b91f6a904bc07f', 'productID': 'Celerra', 'vendorID': 'EMC', 'capacity': '22548578304', 'pathstatus': [{'physdev': 'sdc', 'state': 'active', 'type': 'iSCSI', 'lun': '4'}], 'pvUUID': 'cv45tO-w5Vv-mAxX-C2Ec-63Sq-uhYX-XcMeTz'}, {'status': 'free', 'fwrev': '0002', 'vgUUID': '', 'pathlist': [{'connection': '10.34.63.200', 'iqn': 'iqn.1992-05.com.emc:ckm001201002300000-5-vnxe', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}], 'logicalblocksize': '512', 'devtype': 'iSCSI', 'physicalblocksize': '512', 'serial': 'SEMC_Celerra_EMC-Celerra-iSCSI-VLU-fs76_T5_LUN5_CKM00120100230', 'GUID': '36006048cc786b195adb3de2b6d613cbc', 'productID': 'Celerra', 'vendorID': 'EMC', 'capacity': '22548578304', 'pathstatus': [{'physdev': 'sdd', 'state': 'active', 'type': 'iSCSI', 'lun': '5'}], 'pvUUID': ''}, {'status': 'free', 'fwrev': '0001', 'vgUUID': '', 'pathlist': [{'connection': '10.34.63.204', 'iqn': 'iqn.2012-09.brq.str-02:jlibosva', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}], 'logicalblocksize': '512', 'devtype': 'iSCSI', 'physicalblocksize': '512', 'serial': 'SRH-str02VIRTUAL-DISK', 'GUID': '1jlibosva', 'productID': 'VIRTUAL-DISK', 'vendorID': 'RH-str02', 'capacity': '21474836480', 'pathstatus': [{'physdev': 'sdh', 'state': 'active', 'type': 'iSCSI', 'lun': '1'}], 'pvUUID': 'PCLUOA-wxBR-FLgk-SCM3-MenL-RYWf-qiqFwY'}, {'status': 'free', 'fwrev': '0001', 'vgUUID': '', 'pathlist': [{'connection': '10.34.63.202', 'iqn': 'iqn.2011-01.brq.str-01:pstehlik', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}], 'logicalblocksize': '512', 'devtype': 'iSCSI', 'physicalblocksize': '512', 'serial': 'SRH-str01VIRTUAL-DISK', 'GUID': '1ps01', 'productID': 'VIRTUAL-DISK', 'vendorID': 'RH-str01', 'capacity': '139586437120', 'pathstatus': [{'physdev': 'sdi', 'state': 'active', 'type': 'iSCSI', 'lun': '1'}], 'pvUUID': 'UJ1JCv-ejaX-95oi-A5bF-ZMHa-OGGj-kl11Ux'}, {'status': 'free', 'fwrev': '0001', 'vgUUID': '', 'pathlist': [{'connection': '10.34.63.202', 'iqn': 'iqn.2011-01.brq.str-01:pstehlik', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}], 'logicalblocksize': '512', 'devtype': 'iSCSI', 'physicalblocksize': '512', 'serial': 'SRH-str01VIRTUAL-DISK', 'GUID': '1ps02', 'productID': 'VIRTUAL-DISK', 'vendorID': 'RH-str01', 'capacity': '75161927680', 'pathstatus': [{'physdev': 'sdj', 'state': 'active', 'type': 'iSCSI', 'lun': '2'}], 'pvUUID': '7oLRYL-81F0-6vX3-ZIpd-cUj4-M440-di9F38'}, {'status': 'used', 'fwrev': '0001', 'vgUUID': 'cIvOog-TzN3-BwbK-jXTV-Y07B-mAYt-FahR5H', 'pathlist': [{'connection': '10.34.63.202', 'iqn': 'iqn.2011-01.brq.str-01:pstehlik', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}, {'connection': '10.34.63.204', 'iqn': 'iqn.2011-01.brq.str-02:pstehlik', 'portal': '1', 'port': '3260', 'initiatorname': 'default'}], 'logicalblocksize': '512', 'devtype': 'iSCSI', 'physicalblocksize': '512', 'serial': '', 'GUID': '1pstehlik', 'productID': 'VIRTUAL-DISK', 'vendorID': 'RH-str01', 'capacity': '21474836480', 'pathstatus': [{'physdev': 'sdk', 'state': 'active', 'type': 'iSCSI', 'lun': '3'}, {'physdev': 'sdl', 'state': 'active', 'type': 'iSCSI', 'lun': '1'}], 'pvUUID': 'tjWwz9-i4KV-3wjt-PUn5-fGbe-zX6c-IYtCuj'}]}

Actions: View

Attachments on bug 860719: 617594