Greetings.

Due to an unfortunate storage misconfiguration (iscsi) the Ovirt-node was unable to mount it's master storage domain after a power outage. During the troubleshooting I believe I have managed to get the domain in some weird state where it now remains in status locked.

If trying to take (only) host/node online it goes back to non-operational since it's unable to mount the master storage domain. Rebooting the node and or the engine makes no difference.

Everything storage wise should be OK now.

Any idea on how to recover ?

vdsm.log attached

With kind regards
Jonas
Thread-151::DEBUG::2013-04-18 20:40:00,024::BindingXMLRPC::913::vds::(wrapper) client [46.22.124.43]::call getCapabilities with () {}
Thread-151::DEBUG::2013-04-18 20:40:00,087::BindingXMLRPC::920::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:a07da5fa539'}], 'FC': []}, 'packages2': {'kernel': {'release': '205.fc18.x86_64', 'buildtime': 1361736602.0, 'version': '3.7.9'}, 'spice-server': {'release': '3.fc18', 'buildtime': 1358784016L, 'version': '0.12.2'}, 'vdsm': {'release': '9.fc18', 'buildtime': 1362046220L, 'version': '4.10.3'}, 'qemu-kvm': {'release': '6.fc18', 'buildtime': 1359843954L, 'version': '1.2.2'}, 'libvirt': {'release': '1.fc18', 'buildtime': 1359405439L, 'version': '0.10.2.3'}, 'qemu-img': {'release': '6.fc18', 'buildtime': 1359843954L, 'version': '1.2.2'}, 'mom': {'release': '1.fc18', 'buildtime': 1349470214L, 'version': '0.3.0'}}, 'cpuModel': 'AMD Opteron(TM) Processor 6276', 'hooks': {}, 'cpuSockets': '4', 'vmTypes': ['kvm'], 'supportedProtocols': ['2.2', '2.3'], 'networks': {'ovirtmgmt': {'iface': 'ovirtmgmt', 'addr': '46.22.124.37', 'cfg': {'IPADDR': '46.22.124.37', 'PEERDNS': 'no', 'GATEWAY': '46.22.124.36', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'NETMASK': '255.255.255.224', 'BOOTPROTO': 'none', 'STP': 'no', 'DEVICE': 'ovirtmgmt', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.255.224', 'stp': 'off', 'bridged': True, 'gateway': '46.22.124.36', 'ports': ['em1']}, 'san': {'iface': 'san', 'addr': '192.168.43.11', 'cfg': {'IPADDR': '192.168.43.11', 'PEERDNS': 'no', 'MTU': '9000', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'NETMASK': '255.255.255.0', 'BOOTPROTO': 'none', 'STP': 'no', 'DEVICE': 'san', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '9000', 'netmask': '255.255.255.0', 'stp': 'off', 'bridged': True, 'gateway': '0.0.0.0', 'ports': ['em2']}, 'vminternet': {'iface': 'vminternet', 'addr': '', 'cfg': {'PEERDNS': 'no', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'STP': 'no', 'DEVICE': 'vminternet', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'stp': 'off', 'bridged': True, 'gateway': '0.0.0.0', 'ports': ['em4']}}, 'bridges': {'ovirtmgmt': {'addr': '46.22.124.37', 'cfg': {'IPADDR': '46.22.124.37', 'PEERDNS': 'no', 'GATEWAY': '46.22.124.36', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'NETMASK': '255.255.255.224', 'BOOTPROTO': 'none', 'STP': 'no', 'DEVICE': 'ovirtmgmt', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.255.224', 'stp': 'off', 'ports': ['em1']}, 'san': {'addr': '192.168.43.11', 'cfg': {'IPADDR': '192.168.43.11', 'PEERDNS': 'no', 'MTU': '9000', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'NETMASK': '255.255.255.0', 'BOOTPROTO': 'none', 'STP': 'no', 'DEVICE': 'san', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '9000', 'netmask': '255.255.255.0', 'stp': 'off', 'ports': ['em2']}, 'vminternet': {'addr': '', 'cfg': {'PEERDNS': 'no', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'STP': 'no', 'DEVICE': 'vminternet', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'stp': 'off', 'ports': ['em4']}}, 'uuid': '4C4C4544-0042-4710-8030-B3C04F37354A', 'lastClientIface': 'ovirtmgmt', 'nics': {'em4': {'addr': '', 'cfg': {'BRIDGE': 'vminternet', 'NM_CONTROLLED': 'no', 'PEERDNS': 'no', 'HWADDR': 'd0:67:e5:f9:2e:20', 'STP': 'no', 'DEVICE': 'em4', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': 'd0:67:e5:f9:2e:20', 'speed': 100}, 'em1': {'addr': '', 'cfg': {'BRIDGE': 'ovirtmgmt', 'NM_CONTROLLED': 'no', 'PEERDNS': 'no', 'HWADDR': 'd0:67:e5:f9:2e:1a', 'STP': 'no', 'DEVICE': 'em1', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': 'd0:67:e5:f9:2e:1a', 'speed': 1000}, 'em3': {'addr': '', 'cfg': {'NM_CONTROLLED': 'no', 'PEERDNS': 'no', 'HWADDR': 'd0:67:e5:f9:2e:1e', 'STP': 'no', 'DEVICE': 'em3', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': 'd0:67:e5:f9:2e:1e', 'speed': 0}, 'em2': {'addr': '', 'cfg': {'BRIDGE': 'san', 'NM_CONTROLLED': 'no', 'PEERDNS': 'no', 'MTU': '9000', 'HWADDR': 'd0:67:e5:f9:2e:1c', 'STP': 'no', 'DEVICE': 'em2', 'ONBOOT': 'yes'}, 'mtu': '9000', 'netmask': '', 'hwaddr': 'd0:67:e5:f9:2e:1c', 'speed': 1000}}, 'software_revision': '9', '
clusterLevels': ['3.0', '3.1', '3.2'], 'cpuFlags': u'fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,pse36,clflush,mmx,fxsr,sse,sse2,ht,syscall,nx,mmxext,fxsr_opt,pdpe1gb,rdtscp,lm,constant_tsc,rep_good,nopl,nonstop_tsc,extd_apicid,amd_dcm,aperfmperf,pni,pclmulqdq,monitor,ssse3,cx16,sse4_1,sse4_2,popcnt,aes,xsave,avx,lahf_lm,cmp_legacy,svm,extapic,cr8_legacy,abm,sse4a,misalignsse,3dnowprefetch,osvw,ibs,xop,skinit,wdt,lwp,fma4,nodeid_msr,topoext,perfctr_core,arat,cpb,hw_pstate,npt,lbrv,svm_lock,nrip_save,tsc_scale,vmcb_clean,flushbyasid,decodeassists,pausefilter,pfthreshold,model_Opteron_G3,model_Opteron_G1,model_Opteron_G4,model_Opteron_G2', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:a07da5fa539', 'netConfigDirty': 'False', 'supportedENGINEs': ['3.0', '3.1'], 'reservedMem': '321', 'bondings': {'bond4': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond0': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond1': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond2': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond3': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}}, 'software_version': '4.10', 'memSize': '64210', 'cpuSpeed': '2300.039', 'version_name': 'Snow Man', 'vlans': {}, 'cpuCores': '32', 'kvmEnabled': 'true', 'guestOverhead': '65', 'management_ip': '', 'cpuThreads': '32', 'emulatedMachines': [u'pc-1.2', u'none', u'pc', u'pc-1.1', u'pc-1.0', u'pc-0.15', u'pc-0.14', u'pc-0.13', u'pc-0.12', u'pc-0.11', u'pc-0.10', u'isapc', u'pc-1.2', u'none', u'pc', u'pc-1.1', u'pc-1.0', u'pc-0.15', u'pc-0.14', u'pc-0.13', u'pc-0.12', u'pc-0.11', u'pc-0.10', u'isapc'], 'operatingSystem': {'release': '20120228.fc18', 'version': '2.6.1', 'name': 'oVirt Node'}, 'lastClient': '46.22.124.43'}}
Thread-152::DEBUG::2013-04-18 20:40:00,101::BindingXMLRPC::913::vds::(wrapper) client [46.22.124.43]::call getHardwareInfo with () {}
Thread-152::DEBUG::2013-04-18 20:40:00,103::BindingXMLRPC::920::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'PowerEdge R715', 'systemSerialNumber': '3BG075J', 'systemFamily': 'Not Specified', 'systemVersion': 'Not Specified', 'systemUUID': '4C4C4544-0042-4710-8030-B3C04F37354A', 'systemManufacturer': 'Dell Inc.'}}
Thread-153::DEBUG::2013-04-18 20:40:00,960::BindingXMLRPC::913::vds::(wrapper) client [46.22.124.43]::call getCapabilities with () {}
Thread-153::DEBUG::2013-04-18 20:40:01,015::BindingXMLRPC::920::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:a07da5fa539'}], 'FC': []}, 'packages2': {'kernel': {'release': '205.fc18.x86_64', 'buildtime': 1361736602.0, 'version': '3.7.9'}, 'spice-server': {'release': '3.fc18', 'buildtime': 1358784016L, 'version': '0.12.2'}, 'vdsm': {'release': '9.fc18', 'buildtime': 1362046220L, 'version': '4.10.3'}, 'qemu-kvm': {'release': '6.fc18', 'buildtime': 1359843954L, 'version': '1.2.2'}, 'libvirt': {'release': '1.fc18', 'buildtime': 1359405439L, 'version': '0.10.2.3'}, 'qemu-img': {'release': '6.fc18', 'buildtime': 1359843954L, 'version': '1.2.2'}, 'mom': {'release': '1.fc18', 'buildtime': 1349470214L, 'version': '0.3.0'}}, 'cpuModel': 'AMD Opteron(TM) Processor 6276', 'hooks': {}, 'cpuSockets': '4', 'vmTypes': ['kvm'], 'supportedProtocols': ['2.2', '2.3'], 'networks': {'ovirtmgmt': {'iface': 'ovirtmgmt', 'addr': '46.22.124.37', 'cfg': {'IPADDR': '46.22.124.37', 'PEERDNS': 'no', 'GATEWAY': '46.22.124.36', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'NETMASK': '255.255.255.224', 'BOOTPROTO': 'none', 'STP': 'no', 'DEVICE': 'ovirtmgmt', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.255.224', 'stp': 'off', 'bridged': True, 'gateway': '46.22.124.36', 'ports': ['em1']}, 'san': {'iface': 'san', 'addr': '192.168.43.11', 'cfg': {'IPADDR': '192.168.43.11', 'PEERDNS': 'no', 'MTU': '9000', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'NETMASK': '255.255.255.0', 'BOOTPROTO': 'none', 'STP': 'no', 'DEVICE': 'san', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '9000', 'netmask': '255.255.255.0', 'stp': 'off', 'bridged': True, 'gateway': '0.0.0.0', 'ports': ['em2']}, 'vminternet': {'iface': 'vminternet', 'addr': '', 'cfg': {'PEERDNS': 'no', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'STP': 'no', 'DEVICE': 'vminternet', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'stp': 'off', 'bridged': True, 'gateway': '0.0.0.0', 'ports': ['em4']}}, 'bridges': {'ovirtmgmt': {'addr': '46.22.124.37', 'cfg': {'IPADDR': '46.22.124.37', 'PEERDNS': 'no', 'GATEWAY': '46.22.124.36', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'NETMASK': '255.255.255.224', 'BOOTPROTO': 'none', 'STP': 'no', 'DEVICE': 'ovirtmgmt', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.255.224', 'stp': 'off', 'ports': ['em1']}, 'san': {'addr': '192.168.43.11', 'cfg': {'IPADDR': '192.168.43.11', 'PEERDNS': 'no', 'MTU': '9000', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'NETMASK': '255.255.255.0', 'BOOTPROTO': 'none', 'STP': 'no', 'DEVICE': 'san', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '9000', 'netmask': '255.255.255.0', 'stp': 'off', 'ports': ['em2']}, 'vminternet': {'addr': '', 'cfg': {'PEERDNS': 'no', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'STP': 'no', 'DEVICE': 'vminternet', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'stp': 'off', 'ports': ['em4']}}, 'uuid': '4C4C4544-0042-4710-8030-B3C04F37354A', 'lastClientIface': 'ovirtmgmt', 'nics': {'em4': {'addr': '', 'cfg': {'BRIDGE': 'vminternet', 'NM_CONTROLLED': 'no', 'PEERDNS': 'no', 'HWADDR': 'd0:67:e5:f9:2e:20', 'STP': 'no', 'DEVICE': 'em4', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': 'd0:67:e5:f9:2e:20', 'speed': 100}, 'em1': {'addr': '', 'cfg': {'BRIDGE': 'ovirtmgmt', 'NM_CONTROLLED': 'no', 'PEERDNS': 'no', 'HWADDR': 'd0:67:e5:f9:2e:1a', 'STP': 'no', 'DEVICE': 'em1', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': 'd0:67:e5:f9:2e:1a', 'speed': 1000}, 'em3': {'addr': '', 'cfg': {'NM_CONTROLLED': 'no', 'PEERDNS': 'no', 'HWADDR': 'd0:67:e5:f9:2e:1e', 'STP': 'no', 'DEVICE': 'em3', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': 'd0:67:e5:f9:2e:1e', 'speed': 0}, 'em2': {'addr': '', 'cfg': {'BRIDGE': 'san', 'NM_CONTROLLED': 'no', 'PEERDNS': 'no', 'MTU': '9000', 'HWADDR': 'd0:67:e5:f9:2e:1c', 'STP': 'no', 'DEVICE': 'em2', 'ONBOOT': 'yes'}, 'mtu': '9000', 'netmask': '', 'hwaddr': 'd0:67:e5:f9:2e:1c', 'speed': 1000}}, 'software_revision': '9', '
clusterLevels': ['3.0', '3.1', '3.2'], 'cpuFlags': u'fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,pse36,clflush,mmx,fxsr,sse,sse2,ht,syscall,nx,mmxext,fxsr_opt,pdpe1gb,rdtscp,lm,constant_tsc,rep_good,nopl,nonstop_tsc,extd_apicid,amd_dcm,aperfmperf,pni,pclmulqdq,monitor,ssse3,cx16,sse4_1,sse4_2,popcnt,aes,xsave,avx,lahf_lm,cmp_legacy,svm,extapic,cr8_legacy,abm,sse4a,misalignsse,3dnowprefetch,osvw,ibs,xop,skinit,wdt,lwp,fma4,nodeid_msr,topoext,perfctr_core,arat,cpb,hw_pstate,npt,lbrv,svm_lock,nrip_save,tsc_scale,vmcb_clean,flushbyasid,decodeassists,pausefilter,pfthreshold,model_Opteron_G3,model_Opteron_G1,model_Opteron_G4,model_Opteron_G2', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:a07da5fa539', 'netConfigDirty': 'False', 'supportedENGINEs': ['3.0', '3.1'], 'reservedMem': '321', 'bondings': {'bond4': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond0': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond1': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond2': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond3': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}}, 'software_version': '4.10', 'memSize': '64210', 'cpuSpeed': '2300.039', 'version_name': 'Snow Man', 'vlans': {}, 'cpuCores': '32', 'kvmEnabled': 'true', 'guestOverhead': '65', 'management_ip': '', 'cpuThreads': '32', 'emulatedMachines': [u'pc-1.2', u'none', u'pc', u'pc-1.1', u'pc-1.0', u'pc-0.15', u'pc-0.14', u'pc-0.13', u'pc-0.12', u'pc-0.11', u'pc-0.10', u'isapc', u'pc-1.2', u'none', u'pc', u'pc-1.1', u'pc-1.0', u'pc-0.15', u'pc-0.14', u'pc-0.13', u'pc-0.12', u'pc-0.11', u'pc-0.10', u'isapc'], 'operatingSystem': {'release': '20120228.fc18', 'version': '2.6.1', 'name': 'oVirt Node'}, 'lastClient': '46.22.124.43'}}
Thread-154::DEBUG::2013-04-18 20:40:01,026::BindingXMLRPC::913::vds::(wrapper) client [46.22.124.43]::call getHardwareInfo with () {}
Thread-154::DEBUG::2013-04-18 20:40:01,027::BindingXMLRPC::920::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'PowerEdge R715', 'systemSerialNumber': '3BG075J', 'systemFamily': 'Not Specified', 'systemVersion': 'Not Specified', 'systemUUID': '4C4C4544-0042-4710-8030-B3C04F37354A', 'systemManufacturer': 'Dell Inc.'}}
Thread-156::DEBUG::2013-04-18 20:40:01,085::BindingXMLRPC::161::vds::(wrapper) [46.22.124.43]
Thread-156::DEBUG::2013-04-18 20:40:01,085::task::568::TaskManager.Task::(_updateState) Task=`d267204a-e64f-4a80-8a96-32f757d282f7`::moving from state init -> state preparing
Thread-156::INFO::2013-04-18 20:40:01,086::logUtils::41::dispatcher::(wrapper) Run and protect: validateStorageServerConnection(domType=3, spUUID='dae1ba5e-548a-473e-94b6-7d08d3a6229a', conList=[{'connection': '192.168.43.10', 'iqn': 'iqn.2012-02.se.elementary:ovirt', 'portal': '1', 'user': '', 'password': '******', 'id': '906d9ac3-4ea0-4c5c-bb74-207f768412c4', 'port': '3260'}], options=None)
Thread-156::INFO::2013-04-18 20:40:01,086::logUtils::44::dispatcher::(wrapper) Run and protect: validateStorageServerConnection, Return response: {'statuslist': [{'status': 0, 'id': '906d9ac3-4ea0-4c5c-bb74-207f768412c4'}]}
Thread-156::DEBUG::2013-04-18 20:40:01,086::task::1151::TaskManager.Task::(prepare) Task=`d267204a-e64f-4a80-8a96-32f757d282f7`::finished: {'statuslist': [{'status': 0, 'id': '906d9ac3-4ea0-4c5c-bb74-207f768412c4'}]}
Thread-156::DEBUG::2013-04-18 20:40:01,086::task::568::TaskManager.Task::(_updateState) Task=`d267204a-e64f-4a80-8a96-32f757d282f7`::moving from state preparing -> state finished
Thread-156::DEBUG::2013-04-18 20:40:01,086::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-156::DEBUG::2013-04-18 20:40:01,087::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-156::DEBUG::2013-04-18 20:40:01,087::task::957::TaskManager.Task::(_decref) Task=`d267204a-e64f-4a80-8a96-32f757d282f7`::ref 0 aborting False
Thread-157::DEBUG::2013-04-18 20:40:01,094::BindingXMLRPC::161::vds::(wrapper) [46.22.124.43]
Thread-157::DEBUG::2013-04-18 20:40:01,094::task::568::TaskManager.Task::(_updateState) Task=`129ba07e-d476-4d05-9157-3f83180360f9`::moving from state init -> state preparing
Thread-157::INFO::2013-04-18 20:40:01,095::logUtils::41::dispatcher::(wrapper) Run and protect: validateStorageServerConnection(domType=1, spUUID='dae1ba5e-548a-473e-94b6-7d08d3a6229a', conList=[{'connection': '192.168.43.10:/storage/ovirt/nfs/iso', 'iqn': '', 'portal': '', 'user': '', 'password': '******', 'id': '480ce9bb-4299-43f8-9fe0-8fbac71e54be', 'port': ''}], options=None)
Thread-157::INFO::2013-04-18 20:40:01,095::logUtils::44::dispatcher::(wrapper) Run and protect: validateStorageServerConnection, Return response: {'statuslist': [{'status': 0, 'id': '480ce9bb-4299-43f8-9fe0-8fbac71e54be'}]}
Thread-157::DEBUG::2013-04-18 20:40:01,095::task::1151::TaskManager.Task::(prepare) Task=`129ba07e-d476-4d05-9157-3f83180360f9`::finished: {'statuslist': [{'status': 0, 'id': '480ce9bb-4299-43f8-9fe0-8fbac71e54be'}]}
Thread-157::DEBUG::2013-04-18 20:40:01,095::task::568::TaskManager.Task::(_updateState) Task=`129ba07e-d476-4d05-9157-3f83180360f9`::moving from state preparing -> state finished
Thread-157::DEBUG::2013-04-18 20:40:01,095::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-157::DEBUG::2013-04-18 20:40:01,095::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-157::DEBUG::2013-04-18 20:40:01,095::task::957::TaskManager.Task::(_decref) Task=`129ba07e-d476-4d05-9157-3f83180360f9`::ref 0 aborting False
Thread-158::DEBUG::2013-04-18 20:40:01,102::BindingXMLRPC::161::vds::(wrapper) [46.22.124.43]
Thread-158::DEBUG::2013-04-18 20:40:01,103::task::568::TaskManager.Task::(_updateState) Task=`f966493c-9a0d-4ee6-9c02-64b15cb58b32`::moving from state init -> state preparing
Thread-158::INFO::2013-04-18 20:40:01,103::logUtils::41::dispatcher::(wrapper) Run and protect: validateStorageServerConnection(domType=1, spUUID='dae1ba5e-548a-473e-94b6-7d08d3a6229a', conList=[{'connection': '192.168.43.10:/storage/ovirt/nfs/export_domain', 'iqn': '', 'portal': '', 'user': '', 'password': '******', 'id': 'cbec69e2-884b-4904-89ec-4b947e1f33ba', 'port': ''}], options=None)
Thread-158::INFO::2013-04-18 20:40:01,103::logUtils::44::dispatcher::(wrapper) Run and protect: validateStorageServerConnection, Return response: {'statuslist': [{'status': 0, 'id': 'cbec69e2-884b-4904-89ec-4b947e1f33ba'}]}
Thread-158::DEBUG::2013-04-18 20:40:01,103::task::1151::TaskManager.Task::(prepare) Task=`f966493c-9a0d-4ee6-9c02-64b15cb58b32`::finished: {'statuslist': [{'status': 0, 'id': 'cbec69e2-884b-4904-89ec-4b947e1f33ba'}]}
Thread-158::DEBUG::2013-04-18 20:40:01,103::task::568::TaskManager.Task::(_updateState) Task=`f966493c-9a0d-4ee6-9c02-64b15cb58b32`::moving from state preparing -> state finished
Thread-158::DEBUG::2013-04-18 20:40:01,103::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-158::DEBUG::2013-04-18 20:40:01,104::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-158::DEBUG::2013-04-18 20:40:01,104::task::957::TaskManager.Task::(_decref) Task=`f966493c-9a0d-4ee6-9c02-64b15cb58b32`::ref 0 aborting False
Thread-159::DEBUG::2013-04-18 20:40:01,111::BindingXMLRPC::161::vds::(wrapper) [46.22.124.43]
Thread-159::DEBUG::2013-04-18 20:40:01,111::task::568::TaskManager.Task::(_updateState) Task=`439a0916-9dc1-4237-8116-7a9f574bd3bf`::moving from state init -> state preparing
Thread-159::INFO::2013-04-18 20:40:01,111::logUtils::41::dispatcher::(wrapper) Run and protect: connectStorageServer(domType=3, spUUID='dae1ba5e-548a-473e-94b6-7d08d3a6229a', conList=[{'connection': '192.168.43.10', 'iqn': 'iqn.2012-02.se.elementary:ovirt', 'portal': '1', 'user': '', 'password': '******', 'id': '906d9ac3-4ea0-4c5c-bb74-207f768412c4', 'port': '3260'}], options=None)
Thread-159::DEBUG::2013-04-18 20:40:01,112::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2012-02.se.elementary:ovirt -I default -p 192.168.43.10:3260 --op=new' (cwd None)
Thread-159::DEBUG::2013-04-18 20:40:01,132::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> = ''; <rc> = 0
Thread-159::DEBUG::2013-04-18 20:40:01,133::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2012-02.se.elementary:ovirt -I default -p 192.168.43.10:3260 -l' (cwd None)
Thread-159::DEBUG::2013-04-18 20:40:01,153::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> = ''; <rc> = 0
Thread-159::DEBUG::2013-04-18 20:40:01,153::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2012-02.se.elementary:ovirt -I default -p 192.168.43.10:3260 -n node.startup -v manual --op=update' (cwd None)
Thread-159::DEBUG::2013-04-18 20:40:01,171::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> = ''; <rc> = 0
Thread-159::INFO::2013-04-18 20:40:01,172::logUtils::44::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {'statuslist': [{'status': 0, 'id': '906d9ac3-4ea0-4c5c-bb74-207f768412c4'}]}
Thread-159::DEBUG::2013-04-18 20:40:01,172::task::1151::TaskManager.Task::(prepare) Task=`439a0916-9dc1-4237-8116-7a9f574bd3bf`::finished: {'statuslist': [{'status': 0, 'id': '906d9ac3-4ea0-4c5c-bb74-207f768412c4'}]}
Thread-159::DEBUG::2013-04-18 20:40:01,172::task::568::TaskManager.Task::(_updateState) Task=`439a0916-9dc1-4237-8116-7a9f574bd3bf`::moving from state preparing -> state finished
Thread-159::DEBUG::2013-04-18 20:40:01,172::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-159::DEBUG::2013-04-18 20:40:01,172::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-159::DEBUG::2013-04-18 20:40:01,173::task::957::TaskManager.Task::(_decref) Task=`439a0916-9dc1-4237-8116-7a9f574bd3bf`::ref 0 aborting False
Thread-160::DEBUG::2013-04-18 20:40:01,182::BindingXMLRPC::161::vds::(wrapper) [46.22.124.43]
Thread-160::DEBUG::2013-04-18 20:40:01,182::task::568::TaskManager.Task::(_updateState) Task=`681e4f22-d4a2-47de-95d6-7d5e3960d7f2`::moving from state init -> state preparing
Thread-160::INFO::2013-04-18 20:40:01,183::logUtils::41::dispatcher::(wrapper) Run and protect: connectStorageServer(domType=1, spUUID='dae1ba5e-548a-473e-94b6-7d08d3a6229a', conList=[{'connection': '192.168.43.10:/storage/ovirt/nfs/iso', 'iqn': '', 'portal': '', 'user': '', 'password': '******', 'id': '480ce9bb-4299-43f8-9fe0-8fbac71e54be', 'port': ''}], options=None)
Thread-160::INFO::2013-04-18 20:40:02,370::logUtils::44::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {'statuslist': [{'status': 0, 'id': '480ce9bb-4299-43f8-9fe0-8fbac71e54be'}]}
Thread-160::DEBUG::2013-04-18 20:40:02,370::task::1151::TaskManager.Task::(prepare) Task=`681e4f22-d4a2-47de-95d6-7d5e3960d7f2`::finished: {'statuslist': [{'status': 0, 'id': '480ce9bb-4299-43f8-9fe0-8fbac71e54be'}]}
Thread-160::DEBUG::2013-04-18 20:40:02,371::task::568::TaskManager.Task::(_updateState) Task=`681e4f22-d4a2-47de-95d6-7d5e3960d7f2`::moving from state preparing -> state finished
Thread-160::DEBUG::2013-04-18 20:40:02,371::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-160::DEBUG::2013-04-18 20:40:02,371::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-160::DEBUG::2013-04-18 20:40:02,371::task::957::TaskManager.Task::(_decref) Task=`681e4f22-d4a2-47de-95d6-7d5e3960d7f2`::ref 0 aborting False
Thread-161::DEBUG::2013-04-18 20:40:02,382::BindingXMLRPC::161::vds::(wrapper) [46.22.124.43]
Thread-161::DEBUG::2013-04-18 20:40:02,382::task::568::TaskManager.Task::(_updateState) Task=`69dc0a62-d9a2-4ad4-b2c8-a1f3f353ca35`::moving from state init -> state preparing
Thread-161::INFO::2013-04-18 20:40:02,383::logUtils::41::dispatcher::(wrapper) Run and protect: connectStorageServer(domType=1, spUUID='dae1ba5e-548a-473e-94b6-7d08d3a6229a', conList=[{'connection': '192.168.43.10:/storage/ovirt/nfs/export_domain', 'iqn': '', 'portal': '', 'user': '', 'password': '******', 'id': 'cbec69e2-884b-4904-89ec-4b947e1f33ba', 'port': ''}], options=None)
Thread-161::INFO::2013-04-18 20:40:03,541::logUtils::44::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {'statuslist': [{'status': 0, 'id': 'cbec69e2-884b-4904-89ec-4b947e1f33ba'}]}
Thread-161::DEBUG::2013-04-18 20:40:03,541::task::1151::TaskManager.Task::(prepare) Task=`69dc0a62-d9a2-4ad4-b2c8-a1f3f353ca35`::finished: {'statuslist': [{'status': 0, 'id': 'cbec69e2-884b-4904-89ec-4b947e1f33ba'}]}
Thread-161::DEBUG::2013-04-18 20:40:03,541::task::568::TaskManager.Task::(_updateState) Task=`69dc0a62-d9a2-4ad4-b2c8-a1f3f353ca35`::moving from state preparing -> state finished
Thread-161::DEBUG::2013-04-18 20:40:03,542::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-161::DEBUG::2013-04-18 20:40:03,542::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-161::DEBUG::2013-04-18 20:40:03,542::task::957::TaskManager.Task::(_decref) Task=`69dc0a62-d9a2-4ad4-b2c8-a1f3f353ca35`::ref 0 aborting False
Thread-162::DEBUG::2013-04-18 20:40:03,557::BindingXMLRPC::161::vds::(wrapper) [46.22.124.43]
Thread-162::DEBUG::2013-04-18 20:40:03,557::task::568::TaskManager.Task::(_updateState) Task=`b8b77a2d-790d-4af2-924e-cd9182d4a0a0`::moving from state init -> state preparing
Thread-162::INFO::2013-04-18 20:40:03,557::logUtils::41::dispatcher::(wrapper) Run and protect: connectStoragePool(spUUID='dae1ba5e-548a-473e-94b6-7d08d3a6229a', hostID=1, scsiKey='dae1ba5e-548a-473e-94b6-7d08d3a6229a', msdUUID='ea5643f7-f41f-4c44-a27f-f31240cd0f19', masterVersion=110, options=None)
Thread-162::DEBUG::2013-04-18 20:40:03,558::resourceManager::190::ResourceManager.Request::(__init__) ResName=`Storage.dae1ba5e-548a-473e-94b6-7d08d3a6229a`ReqID=`384ec127-4e36-49d5-8e1f-9f929e7af286`::Request was made in '/usr/share/vdsm/storage/resourceManager.py' line '189' at '__init__'
Thread-162::DEBUG::2013-04-18 20:40:03,558::resourceManager::504::ResourceManager::(registerResource) Trying to register resource 'Storage.dae1ba5e-548a-473e-94b6-7d08d3a6229a' for lock type 'exclusive'
Thread-162::DEBUG::2013-04-18 20:40:03,559::resourceManager::547::ResourceManager::(registerResource) Resource 'Storage.dae1ba5e-548a-473e-94b6-7d08d3a6229a' is free. Now locking as 'exclusive' (1 active user)
Thread-162::DEBUG::2013-04-18 20:40:03,559::resourceManager::227::ResourceManager.Request::(grant) ResName=`Storage.dae1ba5e-548a-473e-94b6-7d08d3a6229a`ReqID=`384ec127-4e36-49d5-8e1f-9f929e7af286`::Granted request
Thread-162::INFO::2013-04-18 20:40:03,559::sp::625::Storage.StoragePool::(connect) Connect host #1 to the storage pool dae1ba5e-548a-473e-94b6-7d08d3a6229a with master domain: ea5643f7-f41f-4c44-a27f-f31240cd0f19 (ver = 110)
Thread-162::DEBUG::2013-04-18 20:40:03,560::lvm::477::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:03,560::lvm::479::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:03,561::lvm::488::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:03,561::lvm::490::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:03,561::lvm::508::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:03,561::lvm::510::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:03,562::misc::1054::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
Thread-162::DEBUG::2013-04-18 20:40:03,562::misc::1056::SamplingMethod::(__call__) Got in to sampling method
Thread-162::DEBUG::2013-04-18 20:40:03,562::misc::1054::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
Thread-162::DEBUG::2013-04-18 20:40:03,562::misc::1056::SamplingMethod::(__call__) Got in to sampling method
Thread-162::DEBUG::2013-04-18 20:40:03,562::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
Thread-162::DEBUG::2013-04-18 20:40:03,589::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> = ''; <rc> = 0
Thread-162::DEBUG::2013-04-18 20:40:03,589::misc::1064::SamplingMethod::(__call__) Returning last result
MainProcess|Thread-162::DEBUG::2013-04-18 20:40:03,592::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd of=/sys/class/scsi_host/host0/scan' (cwd None)
MainProcess|Thread-162::DEBUG::2013-04-18 20:40:03,597::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd of=/sys/class/scsi_host/host1/scan' (cwd None)
MainProcess|Thread-162::DEBUG::2013-04-18 20:40:03,601::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd of=/sys/class/scsi_host/host2/scan' (cwd None)
MainProcess|Thread-162::DEBUG::2013-04-18 20:40:03,605::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd of=/sys/class/scsi_host/host3/scan' (cwd None)
MainProcess|Thread-162::DEBUG::2013-04-18 20:40:03,609::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd of=/sys/class/scsi_host/host4/scan' (cwd None)
MainProcess|Thread-162::DEBUG::2013-04-18 20:40:03,614::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd of=/sys/class/scsi_host/host5/scan' (cwd None)
MainProcess|Thread-162::DEBUG::2013-04-18 20:40:03,618::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd of=/sys/class/scsi_host/host6/scan' (cwd None)
MainProcess|Thread-162::DEBUG::2013-04-18 20:40:03,622::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd of=/sys/class/scsi_host/host7/scan' (cwd None)
MainProcess|Thread-162::DEBUG::2013-04-18 20:40:03,626::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd of=/sys/class/scsi_host/host8/scan' (cwd None)
MainProcess|Thread-162::DEBUG::2013-04-18 20:40:03,631::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd of=/sys/class/scsi_host/host10/scan' (cwd None)
MainProcess|Thread-162::DEBUG::2013-04-18 20:40:03,635::iscsi::402::Storage.ISCSI::(forceIScsiScan) Performing SCSI scan, this will take up to 30 seconds
Thread-162::DEBUG::2013-04-18 20:40:05,639::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/sudo -n /sbin/multipath' (cwd None)
Thread-162::DEBUG::2013-04-18 20:40:05,694::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> = ''; <rc> = 0
Thread-162::DEBUG::2013-04-18 20:40:05,695::lvm::477::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:05,695::lvm::479::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:05,695::lvm::488::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:05,695::lvm::490::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:05,696::lvm::508::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:05,696::lvm::510::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:05,696::misc::1064::SamplingMethod::(__call__) Returning last result
Thread-162::DEBUG::2013-04-18 20:40:05,697::lvm::368::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:05,706::misc::84::Storage.Misc.excCmd::(<lambda>) '/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 = [ \\"a%1IET_00010001|1IET_00010002|1IET_00010003|3500000e019ee26e0|3500000e019ee27f0|3500000e019ee2830|3500000e019efff80|3600508e000000000fdc993aef946ac0f%\\", \\"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 ea5643f7-f41f-4c44-a27f-f31240cd0f19' (cwd None)
Thread-162::DEBUG::2013-04-18 20:40:05,918::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> = ''; <rc> = 0
Thread-162::DEBUG::2013-04-18 20:40:05,920::lvm::397::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:05,921::persistentDict::192::Storage.PersistentDict::(__init__) Created a persistent dict with LvMetadataRW backend
Thread-162::DEBUG::2013-04-18 20:40:07,057::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd iflag=direct skip=0 bs=2048 if=/dev/ea5643f7-f41f-4c44-a27f-f31240cd0f19/metadata count=1' (cwd None)
Thread-162::DEBUG::2013-04-18 20:40:07,067::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> = '1+0 records in\n1+0 records out\n2048 bytes (2.0 kB) copied, 0.00072818 s, 2.8 MB/s\n'; <rc> = 0
Thread-162::DEBUG::2013-04-18 20:40:07,067::misc::325::Storage.Misc::(validateDDBytes) err: ['1+0 records in', '1+0 records out', '2048 bytes (2.0 kB) copied, 0.00072818 s, 2.8 MB/s'], size: 2048
Thread-162::DEBUG::2013-04-18 20:40:07,068::persistentDict::234::Storage.PersistentDict::(refresh) read lines (LvMetadataRW)=[]
Thread-162::WARNING::2013-04-18 20:40:07,068::persistentDict::256::Storage.PersistentDict::(refresh) data has no embedded checksum - trust it as it is
Thread-162::DEBUG::2013-04-18 20:40:07,069::persistentDict::192::Storage.PersistentDict::(__init__) Created a persistent dict with VGTagMetadataRW backend
Thread-162::DEBUG::2013-04-18 20:40:07,070::lvm::483::OperationMutex::(_invalidatevgs) Operation 'lvm invalidate operation' got the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:07,070::lvm::485::OperationMutex::(_invalidatevgs) Operation 'lvm invalidate operation' released the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:07,071::lvm::493::OperationMutex::(_invalidatelvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:07,071::lvm::505::OperationMutex::(_invalidatelvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:07,071::lvm::368::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:07,072::misc::84::Storage.Misc.excCmd::(<lambda>) '/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 = [ \\"a%1IET_00010001|1IET_00010002|1IET_00010003|3500000e019ee26e0|3500000e019ee27f0|3500000e019ee2830|3500000e019efff80|3600508e000000000fdc993aef946ac0f%\\", \\"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 ea5643f7-f41f-4c44-a27f-f31240cd0f19' (cwd None)
Thread-162::DEBUG::2013-04-18 20:40:07,194::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> = ''; <rc> = 0
Thread-162::DEBUG::2013-04-18 20:40:07,196::lvm::397::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:07,197::persistentDict::234::Storage.PersistentDict::(refresh) read lines (VGTagMetadataRW)=['PHYBLKSIZE=4096', 'SDUUID=ea5643f7-f41f-4c44-a27f-f31240cd0f19', 'VERSION=3', 'TYPE=ISCSI', u'PV0=pv:1IET_00020001,uuid:0RBLsc-FB0t-RA6I-d12o-jtUx-lIx3-eQwv8Z,pestart:0,pecount:1951,mapoffset:0', 'LOGBLKSIZE=512', 'LEASERETRIES=3', 'DESCRIPTION=hinken', 'LOCKRENEWALINTERVALSEC=5', 'LOCKPOLICY=', 'VGUUID=5Qox85-NQCz-pyVM-aFRN-KJ2P-jB1T-IiETQr', 'CLASS=Data', 'LEASETIMESEC=60', 'IOOPTIMEOUTSEC=10', 'MASTER_VERSION=1', 'ROLE=Master', 'POOL_DESCRIPTION=Elementary', 'POOL_UUID=dae1ba5e-548a-473e-94b6-7d08d3a6229a', 'POOL_SPM_ID=1', u'POOL_DOMAINS=ea5643f7-f41f-4c44-a27f-f31240cd0f19:Active,c5c68e94-14c6-4b29-8f83-2daa680dc6c0:Active,fecb861a-5cf6-4f1e-8bfe-b7a71e122c2f:Active,9f296bdb-2903-4e8c-a019-f10bc3ae4d17:Active,c7452b13-e72e-4ce8-83e1-79c22f76dabf:Active', 'POOL_SPM_LVER=12', '_SHA_CKSUM=0924d492075d543bc008063efa0cd0239f60920e']
Thread-162::DEBUG::2013-04-18 20:40:07,198::lvm::334::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex
Thread-162::DEBUG::2013-04-18 20:40:07,198::misc::84::Storage.Misc.excCmd::(<lambda>) '/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%1IET_00010001|1IET_00010002|1IET_00010003|3500000e019ee26e0|3500000e019ee27f0|3500000e019ee2830|3500000e019efff80|3600508e000000000fdc993aef946ac0f%\\", \\"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-162::DEBUG::2013-04-18 20:40:07,326::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> = ''; <rc> = 0
Thread-162::DEBUG::2013-04-18 20:40:07,327::lvm::359::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex
Thread-162::WARNING::2013-04-18 20:40:07,328::sd::361::Storage.StorageDomain::(_registerResourceNamespaces) Resource namespace ea5643f7-f41f-4c44-a27f-f31240cd0f19_imageNS already registered
Thread-162::WARNING::2013-04-18 20:40:07,328::sd::369::Storage.StorageDomain::(_registerResourceNamespaces) Resource namespace ea5643f7-f41f-4c44-a27f-f31240cd0f19_volumeNS already registered
Thread-162::WARNING::2013-04-18 20:40:07,328::blockSD::432::Storage.StorageDomain::(_registerResourceNamespaces) Resource namespace ea5643f7-f41f-4c44-a27f-f31240cd0f19_lvmActivationNS already registered
Thread-162::ERROR::2013-04-18 20:40:07,329::sp::1519::Storage.StoragePool::(getMasterDomain) Requested master domain ea5643f7-f41f-4c44-a27f-f31240cd0f19 does not have expected version 110 it is version 1
Thread-162::DEBUG::2013-04-18 20:40:07,329::resourceManager::557::ResourceManager::(releaseResource) Trying to release resource 'Storage.dae1ba5e-548a-473e-94b6-7d08d3a6229a'
Thread-162::DEBUG::2013-04-18 20:40:07,329::resourceManager::573::ResourceManager::(releaseResource) Released resource 'Storage.dae1ba5e-548a-473e-94b6-7d08d3a6229a' (0 active users)
Thread-162::DEBUG::2013-04-18 20:40:07,330::resourceManager::578::ResourceManager::(releaseResource) Resource 'Storage.dae1ba5e-548a-473e-94b6-7d08d3a6229a' is free, finding out if anyone is waiting for it.
Thread-162::DEBUG::2013-04-18 20:40:07,330::resourceManager::585::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.dae1ba5e-548a-473e-94b6-7d08d3a6229a', Clearing records.
Thread-162::ERROR::2013-04-18 20:40:07,330::task::833::TaskManager.Task::(_setError) Task=`b8b77a2d-790d-4af2-924e-cd9182d4a0a0`::Unexpected error
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/task.py", line 840, in _run
  File "/usr/share/vdsm/logUtils.py", line 42, in wrapper
  File "/usr/share/vdsm/storage/hsm.py", line 926, in connectStoragePool
  File "/usr/share/vdsm/storage/hsm.py", line 973, in _connectStoragePool
  File "/usr/share/vdsm/storage/sp.py", line 642, in connect
  File "/usr/share/vdsm/storage/sp.py", line 1166, in __rebuild
  File "/usr/share/vdsm/storage/sp.py", line 1520, in getMasterDomain
StoragePoolWrongMaster: Wrong Master domain or its version: 'SD=ea5643f7-f41f-4c44-a27f-f31240cd0f19, pool=dae1ba5e-548a-473e-94b6-7d08d3a6229a'
Thread-162::DEBUG::2013-04-18 20:40:07,331::task::852::TaskManager.Task::(_run) Task=`b8b77a2d-790d-4af2-924e-cd9182d4a0a0`::Task._run: b8b77a2d-790d-4af2-924e-cd9182d4a0a0 ('dae1ba5e-548a-473e-94b6-7d08d3a6229a', 1, 'dae1ba5e-548a-473e-94b6-7d08d3a6229a', 'ea5643f7-f41f-4c44-a27f-f31240cd0f19', 110) {} failed - stopping task
Thread-162::DEBUG::2013-04-18 20:40:07,331::task::1177::TaskManager.Task::(stop) Task=`b8b77a2d-790d-4af2-924e-cd9182d4a0a0`::stopping in state preparing (force False)
Thread-162::DEBUG::2013-04-18 20:40:07,331::task::957::TaskManager.Task::(_decref) Task=`b8b77a2d-790d-4af2-924e-cd9182d4a0a0`::ref 1 aborting True
Thread-162::INFO::2013-04-18 20:40:07,331::task::1134::TaskManager.Task::(prepare) Task=`b8b77a2d-790d-4af2-924e-cd9182d4a0a0`::aborting: Task is aborted: 'Wrong Master domain or its version' - code 324
Thread-162::DEBUG::2013-04-18 20:40:07,332::task::1139::TaskManager.Task::(prepare) Task=`b8b77a2d-790d-4af2-924e-cd9182d4a0a0`::Prepare: aborted: Wrong Master domain or its version
Thread-162::DEBUG::2013-04-18 20:40:07,332::task::957::TaskManager.Task::(_decref) Task=`b8b77a2d-790d-4af2-924e-cd9182d4a0a0`::ref 0 aborting True
Thread-162::DEBUG::2013-04-18 20:40:07,332::task::892::TaskManager.Task::(_doAbort) Task=`b8b77a2d-790d-4af2-924e-cd9182d4a0a0`::Task._doAbort: force False
Thread-162::DEBUG::2013-04-18 20:40:07,332::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-162::DEBUG::2013-04-18 20:40:07,332::task::568::TaskManager.Task::(_updateState) Task=`b8b77a2d-790d-4af2-924e-cd9182d4a0a0`::moving from state preparing -> state aborting
Thread-162::DEBUG::2013-04-18 20:40:07,332::task::523::TaskManager.Task::(__state_aborting) Task=`b8b77a2d-790d-4af2-924e-cd9182d4a0a0`::_aborting: recover policy none
Thread-162::DEBUG::2013-04-18 20:40:07,333::task::568::TaskManager.Task::(_updateState) Task=`b8b77a2d-790d-4af2-924e-cd9182d4a0a0`::moving from state aborting -> state failed
Thread-162::DEBUG::2013-04-18 20:40:07,333::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-162::DEBUG::2013-04-18 20:40:07,333::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-162::ERROR::2013-04-18 20:40:07,333::dispatcher::67::Storage.Dispatcher.Protect::(run) {'status': {'message': "Wrong Master domain or its version: 'SD=ea5643f7-f41f-4c44-a27f-f31240cd0f19, pool=dae1ba5e-548a-473e-94b6-7d08d3a6229a'", 'code': 324}}

_______________________________________________
Users mailing list
Users@ovirt.org
http://lists.ovirt.org/mailman/listinfo/users

Reply via email to