3:01 p.m.
Greetings.
This post is related to my previous post
(http://lists.ovirt.org/pipermail/users/2013-April/013912.html) but with
some more investigation and findings.
When trying to activate my host/node it goes back to non-operational
since it's unable to attach the master storage domain.
A few snippet from the log (whole log attached):
Thread-12399::ERROR::2013-04-22
11:02:17,627::sp::1519::Storage.StoragePool::(getMasterDomain) Requested
master domain ea5643f7-f41f-4c44-a27f-f31240cd0f19 does not have
expected version 110 it is version 1
Thread-12399::INFO::2013-04-22
11:02:17,630::task::1134::TaskManager.Task::(prepare)
Task=`086e8dc5-7bbd-499e-a12d-736cb14fe79b`::aborting: Task is aborted:
'Wrong Master domain or its version' - code 324
Thread-12399::DEBUG::2013-04-22
11:02:17,630::task::1139::TaskManager.Task::(prepare)
Task=`086e8dc5-7bbd-499e-a12d-736cb14fe79b`::Prepare: aborted: Wrong
Master domain or its version
Not sure if "does not have expected version 110 it is version 1" is a
red herring or if this is actual problem. I get the following output
from vdsClient, where no version seem to match versions from the log.
vdsClient -s 0 getStorageDomainInfo ea5643f7-f41f-4c44-a27f-f31240cd0f19
uuid = ea5643f7-f41f-4c44-a27f-f31240cd0f19
vguuid = 5Qox85-NQCz-pyVM-aFRN-KJ2P-jB1T-IiETQr
lver = -1
state = OK
version = 3
role = Master
pool = ['dae1ba5e-548a-473e-94b6-7d08d3a6229a']
spm_id = -1
type = ISCSI
class = Data
master_ver = 0
name = hinken
Found these that seem somewhat similar:
https://bugzilla.redhat.com/show_bug.cgi?id=784038
http://lists.ovirt.org/pipermail/users/2012-December/010982.html
My whole site is dead now due to this, so any help to the resolve the
issue would be greatly appreciated.
With kind regards
Jonas
vdsm.log
Thread-12388::DEBUG::2013-04-22 11:02:09,292::BindingXMLRPC::913::vds::(wrapper) client
[46.22.124.43]::call getCapabilities with () {}
Thread-12388::DEBUG::2013-04-22 11:02:09,349::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':
'2299.953', '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-12389::DEBUG::2013-04-22 11:02:09,364::BindingXMLRPC::913::vds::(wrapper) client
[46.22.124.43]::call getHardwareInfo with () {}
Thread-12389::DEBUG::2013-04-22 11:02:09,365::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-12390::DEBUG::2013-04-22 11:02:11,238::BindingXMLRPC::913::vds::(wrapper) client
[46.22.124.43]::call getCapabilities with () {}
Thread-12390::DEBUG::2013-04-22 11:02:11,296::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':
'2299.953', '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-12391::DEBUG::2013-04-22 11:02:11,306::BindingXMLRPC::913::vds::(wrapper) client
[46.22.124.43]::call getHardwareInfo with () {}
Thread-12391::DEBUG::2013-04-22 11:02:11,307::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-12393::DEBUG::2013-04-22 11:02:11,366::BindingXMLRPC::161::vds::(wrapper)
[46.22.124.43]
Thread-12393::DEBUG::2013-04-22 11:02:11,367::task::568::TaskManager.Task::(_updateState)
Task=`bf358e1a-079c-4d29-8a9b-99cd5267d4f8`::moving from state init -> state preparing
Thread-12393::INFO::2013-04-22 11:02:11,367::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-12393::INFO::2013-04-22 11:02:11,368::logUtils::44::dispatcher::(wrapper) Run and
protect: validateStorageServerConnection, Return response: {'statuslist':
[{'status': 0, 'id': '906d9ac3-4ea0-4c5c-bb74-207f768412c4'}]}
Thread-12393::DEBUG::2013-04-22 11:02:11,368::task::1151::TaskManager.Task::(prepare)
Task=`bf358e1a-079c-4d29-8a9b-99cd5267d4f8`::finished: {'statuslist':
[{'status': 0, 'id': '906d9ac3-4ea0-4c5c-bb74-207f768412c4'}]}
Thread-12393::DEBUG::2013-04-22 11:02:11,368::task::568::TaskManager.Task::(_updateState)
Task=`bf358e1a-079c-4d29-8a9b-99cd5267d4f8`::moving from state preparing -> state
finished
Thread-12393::DEBUG::2013-04-22
11:02:11,368::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
Thread-12393::DEBUG::2013-04-22
11:02:11,368::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
Thread-12393::DEBUG::2013-04-22 11:02:11,368::task::957::TaskManager.Task::(_decref)
Task=`bf358e1a-079c-4d29-8a9b-99cd5267d4f8`::ref 0 aborting False
Thread-12394::DEBUG::2013-04-22 11:02:11,378::BindingXMLRPC::161::vds::(wrapper)
[46.22.124.43]
Thread-12394::DEBUG::2013-04-22 11:02:11,379::task::568::TaskManager.Task::(_updateState)
Task=`e6d93206-9c45-4326-b1f5-bc74775605a1`::moving from state init -> state preparing
Thread-12394::INFO::2013-04-22 11:02:11,379::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-12394::INFO::2013-04-22 11:02:11,379::logUtils::44::dispatcher::(wrapper) Run and
protect: validateStorageServerConnection, Return response: {'statuslist':
[{'status': 0, 'id': '480ce9bb-4299-43f8-9fe0-8fbac71e54be'}]}
Thread-12394::DEBUG::2013-04-22 11:02:11,379::task::1151::TaskManager.Task::(prepare)
Task=`e6d93206-9c45-4326-b1f5-bc74775605a1`::finished: {'statuslist':
[{'status': 0, 'id': '480ce9bb-4299-43f8-9fe0-8fbac71e54be'}]}
Thread-12394::DEBUG::2013-04-22 11:02:11,379::task::568::TaskManager.Task::(_updateState)
Task=`e6d93206-9c45-4326-b1f5-bc74775605a1`::moving from state preparing -> state
finished
Thread-12394::DEBUG::2013-04-22
11:02:11,380::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
Thread-12394::DEBUG::2013-04-22
11:02:11,380::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
Thread-12394::DEBUG::2013-04-22 11:02:11,380::task::957::TaskManager.Task::(_decref)
Task=`e6d93206-9c45-4326-b1f5-bc74775605a1`::ref 0 aborting False
Thread-12395::DEBUG::2013-04-22 11:02:11,387::BindingXMLRPC::161::vds::(wrapper)
[46.22.124.43]
Thread-12395::DEBUG::2013-04-22 11:02:11,387::task::568::TaskManager.Task::(_updateState)
Task=`5348f964-3322-4250-a78a-d35e682664dd`::moving from state init -> state preparing
Thread-12395::INFO::2013-04-22 11:02:11,388::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-12395::INFO::2013-04-22 11:02:11,388::logUtils::44::dispatcher::(wrapper) Run and
protect: validateStorageServerConnection, Return response: {'statuslist':
[{'status': 0, 'id': 'cbec69e2-884b-4904-89ec-4b947e1f33ba'}]}
Thread-12395::DEBUG::2013-04-22 11:02:11,388::task::1151::TaskManager.Task::(prepare)
Task=`5348f964-3322-4250-a78a-d35e682664dd`::finished: {'statuslist':
[{'status': 0, 'id': 'cbec69e2-884b-4904-89ec-4b947e1f33ba'}]}
Thread-12395::DEBUG::2013-04-22 11:02:11,388::task::568::TaskManager.Task::(_updateState)
Task=`5348f964-3322-4250-a78a-d35e682664dd`::moving from state preparing -> state
finished
Thread-12395::DEBUG::2013-04-22
11:02:11,388::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
Thread-12395::DEBUG::2013-04-22
11:02:11,388::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
Thread-12395::DEBUG::2013-04-22 11:02:11,389::task::957::TaskManager.Task::(_decref)
Task=`5348f964-3322-4250-a78a-d35e682664dd`::ref 0 aborting False
Thread-12396::DEBUG::2013-04-22 11:02:11,396::BindingXMLRPC::161::vds::(wrapper)
[46.22.124.43]
Thread-12396::DEBUG::2013-04-22 11:02:11,396::task::568::TaskManager.Task::(_updateState)
Task=`f5d1e7c3-a014-4d63-983b-6dc088a56f49`::moving from state init -> state preparing
Thread-12396::INFO::2013-04-22 11:02:11,397::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-12396::DEBUG::2013-04-22
11:02:11,397::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-12396::DEBUG::2013-04-22
11:02:11,420::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> =
''; <rc> = 0
Thread-12396::DEBUG::2013-04-22
11:02:11,421::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-12396::DEBUG::2013-04-22
11:02:11,441::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> =
''; <rc> = 0
Thread-12396::DEBUG::2013-04-22
11:02:11,442::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-12396::DEBUG::2013-04-22
11:02:11,460::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> =
''; <rc> = 0
Thread-12396::INFO::2013-04-22 11:02:11,460::logUtils::44::dispatcher::(wrapper) Run and
protect: connectStorageServer, Return response: {'statuslist': [{'status':
0, 'id': '906d9ac3-4ea0-4c5c-bb74-207f768412c4'}]}
Thread-12396::DEBUG::2013-04-22 11:02:11,461::task::1151::TaskManager.Task::(prepare)
Task=`f5d1e7c3-a014-4d63-983b-6dc088a56f49`::finished: {'statuslist':
[{'status': 0, 'id': '906d9ac3-4ea0-4c5c-bb74-207f768412c4'}]}
Thread-12396::DEBUG::2013-04-22 11:02:11,461::task::568::TaskManager.Task::(_updateState)
Task=`f5d1e7c3-a014-4d63-983b-6dc088a56f49`::moving from state preparing -> state
finished
Thread-12396::DEBUG::2013-04-22
11:02:11,461::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
Thread-12396::DEBUG::2013-04-22
11:02:11,461::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
Thread-12396::DEBUG::2013-04-22 11:02:11,462::task::957::TaskManager.Task::(_decref)
Task=`f5d1e7c3-a014-4d63-983b-6dc088a56f49`::ref 0 aborting False
Thread-12397::DEBUG::2013-04-22 11:02:11,470::BindingXMLRPC::161::vds::(wrapper)
[46.22.124.43]
Thread-12397::DEBUG::2013-04-22 11:02:11,470::task::568::TaskManager.Task::(_updateState)
Task=`768743d8-d35d-4a1d-b861-b8ef0d74000c`::moving from state init -> state preparing
Thread-12397::INFO::2013-04-22 11:02:11,471::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-12397::INFO::2013-04-22 11:02:12,695::logUtils::44::dispatcher::(wrapper) Run and
protect: connectStorageServer, Return response: {'statuslist': [{'status':
0, 'id': '480ce9bb-4299-43f8-9fe0-8fbac71e54be'}]}
Thread-12397::DEBUG::2013-04-22 11:02:12,696::task::1151::TaskManager.Task::(prepare)
Task=`768743d8-d35d-4a1d-b861-b8ef0d74000c`::finished: {'statuslist':
[{'status': 0, 'id': '480ce9bb-4299-43f8-9fe0-8fbac71e54be'}]}
Thread-12397::DEBUG::2013-04-22 11:02:12,696::task::568::TaskManager.Task::(_updateState)
Task=`768743d8-d35d-4a1d-b861-b8ef0d74000c`::moving from state preparing -> state
finished
Thread-12397::DEBUG::2013-04-22
11:02:12,696::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
Thread-12397::DEBUG::2013-04-22
11:02:12,696::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
Thread-12397::DEBUG::2013-04-22 11:02:12,696::task::957::TaskManager.Task::(_decref)
Task=`768743d8-d35d-4a1d-b861-b8ef0d74000c`::ref 0 aborting False
Thread-12398::DEBUG::2013-04-22 11:02:12,705::BindingXMLRPC::161::vds::(wrapper)
[46.22.124.43]
Thread-12398::DEBUG::2013-04-22 11:02:12,705::task::568::TaskManager.Task::(_updateState)
Task=`cd8323a6-b1fe-4fc3-a457-c352bb0712f7`::moving from state init -> state preparing
Thread-12398::INFO::2013-04-22 11:02:12,706::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-12398::INFO::2013-04-22 11:02:13,902::logUtils::44::dispatcher::(wrapper) Run and
protect: connectStorageServer, Return response: {'statuslist': [{'status':
0, 'id': 'cbec69e2-884b-4904-89ec-4b947e1f33ba'}]}
Thread-12398::DEBUG::2013-04-22 11:02:13,903::task::1151::TaskManager.Task::(prepare)
Task=`cd8323a6-b1fe-4fc3-a457-c352bb0712f7`::finished: {'statuslist':
[{'status': 0, 'id': 'cbec69e2-884b-4904-89ec-4b947e1f33ba'}]}
Thread-12398::DEBUG::2013-04-22 11:02:13,903::task::568::TaskManager.Task::(_updateState)
Task=`cd8323a6-b1fe-4fc3-a457-c352bb0712f7`::moving from state preparing -> state
finished
Thread-12398::DEBUG::2013-04-22
11:02:13,903::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
Thread-12398::DEBUG::2013-04-22
11:02:13,903::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
Thread-12398::DEBUG::2013-04-22 11:02:13,903::task::957::TaskManager.Task::(_decref)
Task=`cd8323a6-b1fe-4fc3-a457-c352bb0712f7`::ref 0 aborting False
Thread-12399::DEBUG::2013-04-22 11:02:13,917::BindingXMLRPC::161::vds::(wrapper)
[46.22.124.43]
Thread-12399::DEBUG::2013-04-22 11:02:13,917::task::568::TaskManager.Task::(_updateState)
Task=`086e8dc5-7bbd-499e-a12d-736cb14fe79b`::moving from state init -> state preparing
Thread-12399::INFO::2013-04-22 11:02:13,918::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-12399::DEBUG::2013-04-22
11:02:13,918::resourceManager::190::ResourceManager.Request::(__init__)
ResName=`Storage.dae1ba5e-548a-473e-94b6-7d08d3a6229a`ReqID=`15473924-edce-43f6-a4dc-04b7fa1aff61`::Request
was made in '/usr/share/vdsm/storage/resourceManager.py' line '189' at
'__init__'
Thread-12399::DEBUG::2013-04-22
11:02:13,918::resourceManager::504::ResourceManager::(registerResource) Trying to register
resource 'Storage.dae1ba5e-548a-473e-94b6-7d08d3a6229a' for lock type
'exclusive'
Thread-12399::DEBUG::2013-04-22
11:02:13,919::resourceManager::547::ResourceManager::(registerResource) Resource
'Storage.dae1ba5e-548a-473e-94b6-7d08d3a6229a' is free. Now locking as
'exclusive' (1 active user)
Thread-12399::DEBUG::2013-04-22
11:02:13,919::resourceManager::227::ResourceManager.Request::(grant)
ResName=`Storage.dae1ba5e-548a-473e-94b6-7d08d3a6229a`ReqID=`15473924-edce-43f6-a4dc-04b7fa1aff61`::Granted
request
Thread-12399::INFO::2013-04-22 11:02:13,920::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-12399::DEBUG::2013-04-22
11:02:13,920::lvm::477::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate
operation' got the operation mutex
Thread-12399::DEBUG::2013-04-22
11:02:13,921::lvm::479::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate
operation' released the operation mutex
Thread-12399::DEBUG::2013-04-22
11:02:13,921::lvm::488::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate
operation' got the operation mutex
Thread-12399::DEBUG::2013-04-22
11:02:13,921::lvm::490::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate
operation' released the operation mutex
Thread-12399::DEBUG::2013-04-22
11:02:13,921::lvm::508::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate
operation' got the operation mutex
Thread-12399::DEBUG::2013-04-22
11:02:13,922::lvm::510::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate
operation' released the operation mutex
Thread-12399::DEBUG::2013-04-22 11:02:13,922::misc::1054::SamplingMethod::(__call__)
Trying to enter sampling method (storage.sdc.refreshStorage)
Thread-12399::DEBUG::2013-04-22 11:02:13,922::misc::1056::SamplingMethod::(__call__) Got
in to sampling method
Thread-12399::DEBUG::2013-04-22 11:02:13,922::misc::1054::SamplingMethod::(__call__)
Trying to enter sampling method (storage.iscsi.rescan)
Thread-12399::DEBUG::2013-04-22 11:02:13,923::misc::1056::SamplingMethod::(__call__) Got
in to sampling method
Thread-12399::DEBUG::2013-04-22
11:02:13,923::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/sudo -n
/sbin/iscsiadm -m session -R' (cwd None)
Thread-12399::DEBUG::2013-04-22
11:02:13,947::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> =
''; <rc> = 0
Thread-12399::DEBUG::2013-04-22 11:02:13,948::misc::1064::SamplingMethod::(__call__)
Returning last result
MainProcess|Thread-12399::DEBUG::2013-04-22
11:02:13,950::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd
of=/sys/class/scsi_host/host0/scan' (cwd None)
MainProcess|Thread-12399::DEBUG::2013-04-22
11:02:13,955::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd
of=/sys/class/scsi_host/host1/scan' (cwd None)
MainProcess|Thread-12399::DEBUG::2013-04-22
11:02:13,959::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd
of=/sys/class/scsi_host/host2/scan' (cwd None)
MainProcess|Thread-12399::DEBUG::2013-04-22
11:02:13,964::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd
of=/sys/class/scsi_host/host3/scan' (cwd None)
MainProcess|Thread-12399::DEBUG::2013-04-22
11:02:13,968::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd
of=/sys/class/scsi_host/host4/scan' (cwd None)
MainProcess|Thread-12399::DEBUG::2013-04-22
11:02:13,972::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd
of=/sys/class/scsi_host/host5/scan' (cwd None)
MainProcess|Thread-12399::DEBUG::2013-04-22
11:02:13,976::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd
of=/sys/class/scsi_host/host6/scan' (cwd None)
MainProcess|Thread-12399::DEBUG::2013-04-22
11:02:13,980::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd
of=/sys/class/scsi_host/host7/scan' (cwd None)
MainProcess|Thread-12399::DEBUG::2013-04-22
11:02:13,985::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd
of=/sys/class/scsi_host/host8/scan' (cwd None)
MainProcess|Thread-12399::DEBUG::2013-04-22
11:02:13,989::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd
of=/sys/class/scsi_host/host10/scan' (cwd None)
MainProcess|Thread-12399::DEBUG::2013-04-22
11:02:13,993::iscsi::402::Storage.ISCSI::(forceIScsiScan) Performing SCSI scan, this will
take up to 30 seconds
Thread-12399::DEBUG::2013-04-22
11:02:15,997::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/sudo -n
/sbin/multipath' (cwd None)
Thread-12399::DEBUG::2013-04-22
11:02:16,048::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> =
''; <rc> = 0
Thread-12399::DEBUG::2013-04-22
11:02:16,048::lvm::477::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate
operation' got the operation mutex
Thread-12399::DEBUG::2013-04-22
11:02:16,049::lvm::479::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate
operation' released the operation mutex
Thread-12399::DEBUG::2013-04-22
11:02:16,049::lvm::488::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate
operation' got the operation mutex
Thread-12399::DEBUG::2013-04-22
11:02:16,049::lvm::490::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate
operation' released the operation mutex
Thread-12399::DEBUG::2013-04-22
11:02:16,049::lvm::508::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate
operation' got the operation mutex
Thread-12399::DEBUG::2013-04-22
11:02:16,050::lvm::510::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate
operation' released the operation mutex
Thread-12399::DEBUG::2013-04-22 11:02:16,050::misc::1064::SamplingMethod::(__call__)
Returning last result
Thread-12399::DEBUG::2013-04-22 11:02:16,050::lvm::368::OperationMutex::(_reloadvgs)
Operation 'lvm reload operation' got the operation mutex
Thread-12399::DEBUG::2013-04-22
11:02:16,057::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_00020001|1IET_00020002|1IET_00020003|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-12399::DEBUG::2013-04-22
11:02:16,243::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> =
''; <rc> = 0
Thread-12399::DEBUG::2013-04-22 11:02:16,245::lvm::397::OperationMutex::(_reloadvgs)
Operation 'lvm reload operation' released the operation mutex
Thread-12399::DEBUG::2013-04-22
11:02:16,245::persistentDict::192::Storage.PersistentDict::(__init__) Created a persistent
dict with LvMetadataRW backend
Thread-12399::DEBUG::2013-04-22
11:02:17,380::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-12399::DEBUG::2013-04-22
11:02:17,390::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> =
'1+0 records in\n1+0 records out\n2048 bytes (2.0 kB) copied, 0.000642052 s, 3.2
MB/s\n'; <rc> = 0
Thread-12399::DEBUG::2013-04-22 11:02:17,390::misc::325::Storage.Misc::(validateDDBytes)
err: ['1+0 records in', '1+0 records out', '2048 bytes (2.0 kB)
copied, 0.000642052 s, 3.2 MB/s'], size: 2048
Thread-12399::DEBUG::2013-04-22
11:02:17,390::persistentDict::234::Storage.PersistentDict::(refresh) read lines
(LvMetadataRW)=[]
Thread-12399::WARNING::2013-04-22
11:02:17,391::persistentDict::256::Storage.PersistentDict::(refresh) data has no embedded
checksum - trust it as it is
Thread-12399::DEBUG::2013-04-22
11:02:17,392::persistentDict::192::Storage.PersistentDict::(__init__) Created a persistent
dict with VGTagMetadataRW backend
Thread-12399::DEBUG::2013-04-22 11:02:17,392::lvm::483::OperationMutex::(_invalidatevgs)
Operation 'lvm invalidate operation' got the operation mutex
Thread-12399::DEBUG::2013-04-22 11:02:17,393::lvm::485::OperationMutex::(_invalidatevgs)
Operation 'lvm invalidate operation' released the operation mutex
Thread-12399::DEBUG::2013-04-22 11:02:17,393::lvm::493::OperationMutex::(_invalidatelvs)
Operation 'lvm invalidate operation' got the operation mutex
Thread-12399::DEBUG::2013-04-22 11:02:17,393::lvm::505::OperationMutex::(_invalidatelvs)
Operation 'lvm invalidate operation' released the operation mutex
Thread-12399::DEBUG::2013-04-22 11:02:17,394::lvm::368::OperationMutex::(_reloadvgs)
Operation 'lvm reload operation' got the operation mutex
Thread-12399::DEBUG::2013-04-22
11:02:17,394::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_00020001|1IET_00020002|1IET_00020003|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-12399::DEBUG::2013-04-22
11:02:17,504::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> =
''; <rc> = 0
Thread-12399::DEBUG::2013-04-22 11:02:17,506::lvm::397::OperationMutex::(_reloadvgs)
Operation 'lvm reload operation' released the operation mutex
Thread-12399::DEBUG::2013-04-22
11:02:17,507::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-12399::DEBUG::2013-04-22 11:02:17,508::lvm::334::OperationMutex::(_reloadpvs)
Operation 'lvm reload operation' got the operation mutex
Thread-12399::DEBUG::2013-04-22
11:02:17,508::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_00020001|1IET_00020002|1IET_00020003|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-12399::DEBUG::2013-04-22
11:02:17,624::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> =
''; <rc> = 0
Thread-12399::DEBUG::2013-04-22 11:02:17,625::lvm::359::OperationMutex::(_reloadpvs)
Operation 'lvm reload operation' released the operation mutex
Thread-12399::WARNING::2013-04-22
11:02:17,626::sd::361::Storage.StorageDomain::(_registerResourceNamespaces) Resource
namespace ea5643f7-f41f-4c44-a27f-f31240cd0f19_imageNS already registered
Thread-12399::WARNING::2013-04-22
11:02:17,626::sd::369::Storage.StorageDomain::(_registerResourceNamespaces) Resource
namespace ea5643f7-f41f-4c44-a27f-f31240cd0f19_volumeNS already registered
Thread-12399::WARNING::2013-04-22
11:02:17,626::blockSD::432::Storage.StorageDomain::(_registerResourceNamespaces) Resource
namespace ea5643f7-f41f-4c44-a27f-f31240cd0f19_lvmActivationNS already registered
Thread-12399::ERROR::2013-04-22
11:02:17,627::sp::1519::Storage.StoragePool::(getMasterDomain) Requested master domain
ea5643f7-f41f-4c44-a27f-f31240cd0f19 does not have expected version 110 it is version 1
Thread-12399::DEBUG::2013-04-22
11:02:17,627::resourceManager::557::ResourceManager::(releaseResource) Trying to release
resource 'Storage.dae1ba5e-548a-473e-94b6-7d08d3a6229a'
Thread-12399::DEBUG::2013-04-22
11:02:17,628::resourceManager::573::ResourceManager::(releaseResource) Released resource
'Storage.dae1ba5e-548a-473e-94b6-7d08d3a6229a' (0 active users)
Thread-12399::DEBUG::2013-04-22
11:02:17,628::resourceManager::578::ResourceManager::(releaseResource) Resource
'Storage.dae1ba5e-548a-473e-94b6-7d08d3a6229a' is free, finding out if anyone is
waiting for it.
Thread-12399::DEBUG::2013-04-22
11:02:17,628::resourceManager::585::ResourceManager::(releaseResource) No one is waiting
for resource 'Storage.dae1ba5e-548a-473e-94b6-7d08d3a6229a', Clearing records.
Thread-12399::ERROR::2013-04-22 11:02:17,628::task::833::TaskManager.Task::(_setError)
Task=`086e8dc5-7bbd-499e-a12d-736cb14fe79b`::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-12399::DEBUG::2013-04-22 11:02:17,629::task::852::TaskManager.Task::(_run)
Task=`086e8dc5-7bbd-499e-a12d-736cb14fe79b`::Task._run:
086e8dc5-7bbd-499e-a12d-736cb14fe79b ('dae1ba5e-548a-473e-94b6-7d08d3a6229a', 1,
'dae1ba5e-548a-473e-94b6-7d08d3a6229a',
'ea5643f7-f41f-4c44-a27f-f31240cd0f19', 110) {} failed - stopping task
Thread-12399::DEBUG::2013-04-22 11:02:17,629::task::1177::TaskManager.Task::(stop)
Task=`086e8dc5-7bbd-499e-a12d-736cb14fe79b`::stopping in state preparing (force False)
Thread-12399::DEBUG::2013-04-22 11:02:17,630::task::957::TaskManager.Task::(_decref)
Task=`086e8dc5-7bbd-499e-a12d-736cb14fe79b`::ref 1 aborting True
Thread-12399::INFO::2013-04-22 11:02:17,630::task::1134::TaskManager.Task::(prepare)
Task=`086e8dc5-7bbd-499e-a12d-736cb14fe79b`::aborting: Task is aborted: 'Wrong Master
domain or its version' - code 324
Thread-12399::DEBUG::2013-04-22 11:02:17,630::task::1139::TaskManager.Task::(prepare)
Task=`086e8dc5-7bbd-499e-a12d-736cb14fe79b`::Prepare: aborted: Wrong Master domain or its
version
Thread-12399::DEBUG::2013-04-22 11:02:17,630::task::957::TaskManager.Task::(_decref)
Task=`086e8dc5-7bbd-499e-a12d-736cb14fe79b`::ref 0 aborting True
Thread-12399::DEBUG::2013-04-22 11:02:17,630::task::892::TaskManager.Task::(_doAbort)
Task=`086e8dc5-7bbd-499e-a12d-736cb14fe79b`::Task._doAbort: force False
Thread-12399::DEBUG::2013-04-22
11:02:17,631::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
Thread-12399::DEBUG::2013-04-22 11:02:17,631::task::568::TaskManager.Task::(_updateState)
Task=`086e8dc5-7bbd-499e-a12d-736cb14fe79b`::moving from state preparing -> state
aborting
Thread-12399::DEBUG::2013-04-22
11:02:17,631::task::523::TaskManager.Task::(__state_aborting)
Task=`086e8dc5-7bbd-499e-a12d-736cb14fe79b`::_aborting: recover policy none
Thread-12399::DEBUG::2013-04-22 11:02:17,631::task::568::TaskManager.Task::(_updateState)
Task=`086e8dc5-7bbd-499e-a12d-736cb14fe79b`::moving from state aborting -> state
failed
Thread-12399::DEBUG::2013-04-22
11:02:17,631::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
Thread-12399::DEBUG::2013-04-22
11:02:17,632::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
Thread-12399::ERROR::2013-04-22
11:02:17,632::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}}