<div dir="ltr"><div class="gmail_default" style="font-family:tahoma,sans-serif">Looks like the multipath rules ovirt seems to setup by default, not sure why..</div><div class="gmail_default" style="font-family:tahoma,sans-serif">

I just blacklist my (HDD) devices, otherwise my consoles get filled with a similar message.<br></div><div class="gmail_extra"><br><div class="gmail_quote">On Thu, Jul 17, 2014 at 5:41 AM, Chris Adams <span dir="ltr">&lt;<a href="mailto:cma@cmadams.net" target="_blank">cma@cmadams.net</a>&gt;</span> wrote:<br>

<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">I built a new node+hosted engine setup, using up-to-date 6.5 and oVirt<br>
3.4.3-RC.  I see some odd messages, that I think are probably related:<br>
<br>
- In the hosted engine UI, I have an Alert that says &quot;Failed to verify<br>
  Power Management configuration for Host hosted_engine_1.&quot;<br>
<br>
- On the node, I get the following chunk repeated every 10 seconds in<br>
  /var/log/messages:<br>
<br>
Jul 16 14:34:19 node0 kernel: device-mapper: table: 253:2: multipath: error getting device<br>
Jul 16 14:34:19 node0 kernel: device-mapper: ioctl: error adding target to table<br>
Jul 16 14:34:19 node0 kernel: device-mapper: table: 253:2: multipath: error getting device<br>
Jul 16 14:34:19 node0 kernel: device-mapper: ioctl: error adding target to table<br>
Jul 16 14:34:19 node0 multipathd: dm-2: remove map (uevent)<br>
Jul 16 14:34:19 node0 multipathd: dm-2: devmap not registered, can&#39;t remove<br>
Jul 16 14:34:19 node0 cpuspeed: Disabling performance cpu frequency scaling governor<br>
Jul 16 14:34:19 node0 multipathd: dm-2: remove map (uevent)<br>
Jul 16 14:34:19 node0 multipathd: dm-2: devmap not registered, can&#39;t remove<br>
Jul 16 14:34:19 node0 multipathd: dm-2: remove map (uevent)<br>
Jul 16 14:34:19 node0 multipathd: dm-2: devmap not registered, can&#39;t remove<br>
Jul 16 14:34:19 node0 multipathd: dm-2: remove map (uevent)<br>
Jul 16 14:34:19 node0 multipathd: dm-2: devmap not registered, can&#39;t remove<br>
Jul 16 14:34:20 node0 cpuspeed: Enabling performance cpu frequency scaling governor<br>
<br>
There is no dm-2; the system is installed on 2 SAS drives, mirrored<br>
using Linux md RAID1, using LVM (dm-0 is the root filesystem and dm-1 is<br>
swap).<br>
<br>
Here&#39;s the corresponding chunk of /var/log/vdsm/vdsm.log:<br>
<br>
Thread-128::DEBUG::2014-07-16 14:34:19,092::task::595::TaskManager.Task::(_updateState) Task=`6db0f7ed-ec65-4685-ae2d-604560349317`::moving from state init -&gt; state preparing<br>
Thread-128::INFO::2014-07-16 14:34:19,092::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None)<br>
Thread-128::INFO::2014-07-16 14:34:19,093::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {&#39;74cb6a07-5745-4b21-ba4b-d9012acb5cae&#39;: {&#39;code&#39;: 0, &#39;version&#39;: 3, &#39;acquired&#39;: True, &#39;delay&#39;: &#39;0.000485922&#39;, &#39;lastCheck&#39;: &#39;9.4&#39;, &#39;valid&#39;: True}}<br>


Thread-128::DEBUG::2014-07-16 14:34:19,093::task::1185::TaskManager.Task::(prepare) Task=`6db0f7ed-ec65-4685-ae2d-604560349317`::finished: {&#39;74cb6a07-5745-4b21-ba4b-d9012acb5cae&#39;: {&#39;code&#39;: 0, &#39;version&#39;: 3, &#39;acquired&#39;: True, &#39;delay&#39;: &#39;0.000485922&#39;, &#39;lastCheck&#39;: &#39;9.4&#39;, &#39;valid&#39;: True}}<br>


Thread-128::DEBUG::2014-07-16 14:34:19,094::task::595::TaskManager.Task::(_updateState) Task=`6db0f7ed-ec65-4685-ae2d-604560349317`::moving from state preparing -&gt; state finished<br>
Thread-128::DEBUG::2014-07-16 14:34:19,094::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}<br>
Thread-128::DEBUG::2014-07-16 14:34:19,094::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>
Thread-128::DEBUG::2014-07-16 14:34:19,095::task::990::TaskManager.Task::(_decref) Task=`6db0f7ed-ec65-4685-ae2d-604560349317`::ref 0 aborting False<br>
Thread-2011::DEBUG::2014-07-16 14:34:19,369::BindingXMLRPC::251::vds::(wrapper) client [127.0.0.1]<br>
Thread-2011::DEBUG::2014-07-16 14:34:19,370::task::595::TaskManager.Task::(_updateState) Task=`44641295-7f85-40f9-ba71-6f587a96f387`::moving from state init -&gt; state preparing<br>
Thread-2011::INFO::2014-07-16 14:34:19,371::logUtils::44::dispatcher::(wrapper) Run and protect: connectStorageServer(domType=1, spUUID=&#39;b15478ff-1ae1-4065-8e52-19c808d39597&#39;, conList=[{&#39;port&#39;: &#39;&#39;, &#39;connection&#39;: &#39;nfs.c1.api-digital.com:/vmstore/engine&#39;, &#39;iqn&#39;: &#39;&#39;, &#39;portal&#39;: &#39;&#39;, &#39;user&#39;: &#39;kvm&#39;, &#39;protocol_version&#39;: &#39;4&#39;, &#39;password&#39;: &#39;******&#39;, &#39;id&#39;: &#39;7fb481a8-f7b2-4cf7-8862-8ff02acde48d&#39;}], options=None)<br>


Thread-2011::DEBUG::2014-07-16 14:34:19,376::hsm::2328::Storage.HSM::(__prefetchDomains) nfs local path: /rhev/data-center/mnt/nfs.c1.api-digital.com:_vmstore_engine<br>
Thread-2011::DEBUG::2014-07-16 14:34:19,378::hsm::2352::Storage.HSM::(__prefetchDomains) Found SD uuids: (&#39;74cb6a07-5745-4b21-ba4b-d9012acb5cae&#39;,)<br>
Thread-2011::DEBUG::2014-07-16 14:34:19,379::hsm::2408::Storage.HSM::(connectStorageServer) knownSDs: {74cb6a07-5745-4b21-ba4b-d9012acb5cae: storage.nfsSD.findDomain}<br>
Thread-2011::INFO::2014-07-16 14:34:19,379::logUtils::47::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {&#39;statuslist&#39;: [{&#39;status&#39;: 0, &#39;id&#39;: &#39;7fb481a8-f7b2-4cf7-8862-8ff02acde48d&#39;}]}<br>


Thread-2011::DEBUG::2014-07-16 14:34:19,379::task::1185::TaskManager.Task::(prepare) Task=`44641295-7f85-40f9-ba71-6f587a96f387`::finished: {&#39;statuslist&#39;: [{&#39;status&#39;: 0, &#39;id&#39;: &#39;7fb481a8-f7b2-4cf7-8862-8ff02acde48d&#39;}]}<br>


Thread-2011::DEBUG::2014-07-16 14:34:19,379::task::595::TaskManager.Task::(_updateState) Task=`44641295-7f85-40f9-ba71-6f587a96f387`::moving from state preparing -&gt; state finished<br>
Thread-2011::DEBUG::2014-07-16 14:34:19,380::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}<br>
Thread-2011::DEBUG::2014-07-16 14:34:19,380::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>
Thread-2011::DEBUG::2014-07-16 14:34:19,380::task::990::TaskManager.Task::(_decref) Task=`44641295-7f85-40f9-ba71-6f587a96f387`::ref 0 aborting False<br>
Thread-2012::DEBUG::2014-07-16 14:34:19,571::BindingXMLRPC::251::vds::(wrapper) client [127.0.0.1]<br>
Thread-2012::DEBUG::2014-07-16 14:34:19,572::task::595::TaskManager.Task::(_updateState) Task=`a1e6fda0-5839-4a07-938f-76eb1705e654`::moving from state init -&gt; state preparing<br>
Thread-2012::INFO::2014-07-16 14:34:19,573::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None)<br>
Thread-2012::INFO::2014-07-16 14:34:19,573::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {&#39;74cb6a07-5745-4b21-ba4b-d9012acb5cae&#39;: {&#39;code&#39;: 0, &#39;version&#39;: 3, &#39;acquired&#39;: True, &#39;delay&#39;: &#39;0.000485922&#39;, &#39;lastCheck&#39;: &#39;9.9&#39;, &#39;valid&#39;: True}}<br>


Thread-2012::DEBUG::2014-07-16 14:34:19,573::task::1185::TaskManager.Task::(prepare) Task=`a1e6fda0-5839-4a07-938f-76eb1705e654`::finished: {&#39;74cb6a07-5745-4b21-ba4b-d9012acb5cae&#39;: {&#39;code&#39;: 0, &#39;version&#39;: 3, &#39;acquired&#39;: True, &#39;delay&#39;: &#39;0.000485922&#39;, &#39;lastCheck&#39;: &#39;9.9&#39;, &#39;valid&#39;: True}}<br>


Thread-2012::DEBUG::2014-07-16 14:34:19,574::task::595::TaskManager.Task::(_updateState) Task=`a1e6fda0-5839-4a07-938f-76eb1705e654`::moving from state preparing -&gt; state finished<br>
Thread-2012::DEBUG::2014-07-16 14:34:19,574::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}<br>
Thread-2012::DEBUG::2014-07-16 14:34:19,574::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>
Thread-2012::DEBUG::2014-07-16 14:34:19,574::task::990::TaskManager.Task::(_decref) Task=`a1e6fda0-5839-4a07-938f-76eb1705e654`::ref 0 aborting False<br>
Thread-40::DEBUG::2014-07-16 14:34:19,664::misc::756::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)<br>
Thread-40::DEBUG::2014-07-16 14:34:19,665::misc::758::SamplingMethod::(__call__) Got in to sampling method<br>
Thread-40::DEBUG::2014-07-16 14:34:19,665::misc::756::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)<br>
Thread-40::DEBUG::2014-07-16 14:34:19,666::misc::758::SamplingMethod::(__call__) Got in to sampling method<br>
Thread-40::DEBUG::2014-07-16 14:34:19,666::iscsi::407::Storage.ISCSI::(rescan) Performing SCSI scan, this will take up to 30 seconds<br>
Thread-40::DEBUG::2014-07-16 14:34:19,666::iscsiadm::92::Storage.Misc.excCmd::(_runCmd) &#39;/usr/bin/sudo -n /sbin/iscsiadm -m session -R&#39; (cwd None)<br>
Thread-40::DEBUG::2014-07-16 14:34:19,709::misc::766::SamplingMethod::(__call__) Returning last result<br>
Thread-40::DEBUG::2014-07-16 14:34:19,710::multipath::109::Storage.Misc.excCmd::(rescan) &#39;/usr/bin/sudo -n /sbin/multipath&#39; (cwd None)<br>
Thread-40::DEBUG::2014-07-16 14:34:19,842::multipath::109::Storage.Misc.excCmd::(rescan) SUCCESS: &lt;err&gt; = &#39;&#39;; &lt;rc&gt; = 0<br>
Thread-40::DEBUG::2014-07-16 14:34:19,843::lvm::497::OperationMutex::(_invalidateAllPvs) Operation &#39;lvm invalidate operation&#39; got the operation mutex<br>
Thread-40::DEBUG::2014-07-16 14:34:19,844::lvm::499::OperationMutex::(_invalidateAllPvs) Operation &#39;lvm invalidate operation&#39; released the operation mutex<br>
Thread-40::DEBUG::2014-07-16 14:34:19,844::lvm::508::OperationMutex::(_invalidateAllVgs) Operation &#39;lvm invalidate operation&#39; got the operation mutex<br>
Thread-40::DEBUG::2014-07-16 14:34:19,845::lvm::510::OperationMutex::(_invalidateAllVgs) Operation &#39;lvm invalidate operation&#39; released the operation mutex<br>
Thread-40::DEBUG::2014-07-16 14:34:19,845::lvm::528::OperationMutex::(_invalidateAllLvs) Operation &#39;lvm invalidate operation&#39; got the operation mutex<br>
Thread-40::DEBUG::2014-07-16 14:34:19,846::lvm::530::OperationMutex::(_invalidateAllLvs) Operation &#39;lvm invalidate operation&#39; released the operation mutex<br>
Thread-40::DEBUG::2014-07-16 14:34:19,846::misc::766::SamplingMethod::(__call__) Returning last result<br>
Thread-40::DEBUG::2014-07-16 14:34:19,854::fileSD::150::Storage.StorageDomain::(__init__) Reading domain in path /rhev/data-center/mnt/nfs.c1.api-digital.com:_vmstore_engine/74cb6a07-5745-4b21-ba4b-d9012acb5cae<br>
Thread-40::DEBUG::2014-07-16 14:34:19,856::persistentDict::192::Storage.PersistentDict::(__init__) Created a persistent dict with FileMetadataRW backend<br>
Thread-40::DEBUG::2014-07-16 14:34:19,860::persistentDict::234::Storage.PersistentDict::(refresh) read lines (FileMetadataRW)=[&#39;CLASS=Data&#39;, &#39;DESCRIPTION=hosted_storage&#39;, &#39;IOOPTIMEOUTSEC=10&#39;, &#39;LEASERETRIES=3&#39;, &#39;LEASETIMESEC=60&#39;, &#39;LOCKPOLICY=ON&#39;, &#39;LOCKRENEWALINTERVALSEC=5&#39;, &#39;MASTER_VERSION=1&#39;, &#39;POOL_DESCRIPTION=c1&#39;, &#39;POOL_DOMAINS=74cb6a07-5745-4b21-ba4b-d9012acb5cae:Active&#39;, &#39;POOL_SPM_ID=-1&#39;, &#39;POOL_SPM_LVER=0&#39;, &#39;POOL_UUID=b15478ff-1ae1-4065-8e52-19c808d39597&#39;, &#39;REMOTE_PATH=nfs.c1.api-digital.com:/vmstore/engine&#39;, &#39;ROLE=Master&#39;, &#39;SDUUID=74cb6a07-5745-4b21-ba4b-d9012acb5cae&#39;, &#39;TYPE=NFS&#39;, &#39;VERSION=3&#39;, &#39;_SHA_CKSUM=4f007c871da3177ba5546459bcebc8be8aff689e&#39;]<br>


Thread-40::DEBUG::2014-07-16 14:34:19,863::fileSD::609::Storage.StorageDomain::(imageGarbageCollector) Removing remnants of deleted images []<br>
Thread-40::INFO::2014-07-16 14:34:19,863::sd::383::Storage.StorageDomain::(_registerResourceNamespaces) Resource namespace 74cb6a07-5745-4b21-ba4b-d9012acb5cae_imageNS already registered<br>
Thread-40::INFO::2014-07-16 14:34:19,863::sd::391::Storage.StorageDomain::(_registerResourceNamespaces) Resource namespace 74cb6a07-5745-4b21-ba4b-d9012acb5cae_volumeNS already registered<br>
Thread-40::DEBUG::2014-07-16 14:34:19,868::fileSD::259::Storage.Misc.excCmd::(getReadDelay) &#39;/bin/dd iflag=direct if=/rhev/data-center/mnt/nfs.c1.api-digital.com:_vmstore_engine/74cb6a07-5745-4b21-ba4b-d9012acb5cae/dom_md/metadata bs=4096 count=1&#39; (cwd None)<br>


Thread-40::DEBUG::2014-07-16 14:34:19,885::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: &lt;err&gt; = &#39;0+1 records in\n0+1 records out\n476 bytes (476 B) copied, 0.000548138 s, 868 kB/s\n&#39;; &lt;rc&gt; = 0<br>


<span class="HOEnZb"><font color="#888888"><br>
--<br>
Chris Adams &lt;<a href="mailto:cma@cmadams.net">cma@cmadams.net</a>&gt;<br>
_______________________________________________<br>
Users mailing list<br>
<a href="mailto:Users@ovirt.org">Users@ovirt.org</a><br>
<a href="http://lists.ovirt.org/mailman/listinfo/users" target="_blank">http://lists.ovirt.org/mailman/listinfo/users</a><br>
</font></span></blockquote></div><br></div></div>