<html>

  <head>

    <meta content="text/html; charset=UTF-8" http-equiv="Content-Type">

  </head>

  <body style="font-family: sans-serif; font-size: 16px;" text="#000000"

    bgcolor="#FFFFFF">

    <div id="QCMcontainer"

      style="font-family:sans-serif;font-size:16px;"><br>

      <br>

      <span style="color:#000000; font-family:sans-serif;

        font-size:12px; font-weight:normal" class="headerSpan">

        <div class="moz-cite-prefix">Il 09/06/2013 08:38, Dafna Ron ha

          scritto:<br>

        </div>

      </span>

      <blockquote style="border-left: 2px solid rgb(0, 153, 0) !

        important; border-right: 2px solid rgb(0, 153, 0) ! important;

        padding: 0px 15px; margin: 8px 2px; font-size: medium;"

        cite="mid:51B422F2.30305@redhat.com" type="cite"><!--[if !IE]><DIV style="border-left: 2px solid #009900; border-right: 2px solid #009900;  padding: 0px 15px; margin: 2px 0px;"><![endif]-->please

        attach the full logs :)

        <br>

        <br>

        <br>

        On 06/06/2013 05:47 PM, Alessandro Bianchi wrote:

        <br>

        <blockquote style="border-left: 2px solid #009900 !important;

          border-right: 2px solid #009900 !important; padding: 0px 15px

          0px 15px; margin: 8px 2px;" type="cite"><!--[if !IE]><DIV style="border-left: 2px solid #009900; border-right: 2px solid #009900;  padding: 0px 15px; margin: 2px 0px;"><![endif]-->

          <br>

          <br>

          Il 06/06/2013 15:55, <a class="moz-txt-link-abbreviated" href="mailto:users-request@ovirt.org">users-request@ovirt.org</a> ha scritto:

          <br>

          <blockquote style="border-left: 2px solid #009900 !important;

            border-right: 2px solid #009900 !important; padding: 0px

            15px 0px 15px; margin: 8px 2px;" type="cite"><!--[if !IE]><DIV style="border-left: 2px solid #009900; border-right: 2px solid #009900;  padding: 0px 15px; margin: 2px 0px;"><![endif]-->Message:

            5

            <br>

            Date: Thu, 06 Jun 2013 15:38:48 +0300

            <br>

            From: Dafna Ron<a class="moz-txt-link-rfc2396E" href="mailto:dron@redhat.com">&lt;dron@redhat.com&gt;</a>

            <br>

            <a class="moz-txt-link-abbreviated" href="mailto:To:users@ovirt.org">To:users@ovirt.org</a>

            <br>

            Subject: Re: [Users] SD Again

            <br>

            Message-ID:<a class="moz-txt-link-rfc2396E" href="mailto:51B082D8.5040700@redhat.com">&lt;51B082D8.5040700@redhat.com&gt;</a>

            <br>

            Content-Type: text/plain; charset=ISO-8859-1; format=flowed

            <br>

            <br>

            You can attach full engine and vdsm logs and I'll try to

            debug it (I

            <br>

            need to see the first umount).

            <br>

            <br>

            <br>

            <br>

            On 06/06/2013 02:25 PM, Alessandro Bianchi wrote:

            <br>

            <blockquote style="border-left: 2px solid #009900

              !important; border-right: 2px solid #009900 !important;

              padding: 0px 15px 0px 15px; margin: 8px 2px;" type="cite"><!--[if !IE]><DIV style="border-left: 2px solid #009900; border-right: 2px solid #009900;  padding: 0px 15px; margin: 2px 0px;"><![endif]-->&gt;Hi

              guys

              <br>

              &gt;

              <br>

              &gt;I solved manually remounting the Expord SD after

              restarting the NFS

              <br>

              &gt;server and then detaching the export domain

              <br>

              &gt;

              <br>

              &gt;I wonder if someone knows why this rhings happen ...

              <br>

              &gt;

              <br>

              &gt;Best regards

              <br>

              &gt;

              <br>

              &gt;

              <br>

              <!--[if !IE]></DIV><![endif]--></blockquote>

            <!--[if !IE]></DIV><![endif]--></blockquote>

          Hope I'm providing the right stuff

          <br>

          <br>

          I may send you all the file but these are the relevat infos I

          suppose

          <br>

          <br>

          vdsm.log

          <br>

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:49,932::BindingXMLRPC::161::vds::(wrapper) [172.16.0.5]

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:49,932::task::568::TaskManager.Task::(_updateState)

          Task=`c0d1c115-cb3d-4f39-8c9b-448401097921`::moving from state

          init -&gt; state preparing

          <br>

          Thread-281877::<a class="moz-txt-link-freetext" href="INFO::2013-06-06">INFO::2013-06-06</a>

          12:36:49,933::logUtils::41::dispatcher::(wrapper) Run and

          protect: disconnectStorageServer(domType=1,

          spUUID='00000000-0000-0000-0000-000000000000',

          conList=[{'connection': '172.16.0.5:/home/external/migration',

          'iqn': '', 'portal': '', 'user': '', 'password': '******',

          'id': '45085cbf-da10-4852-9d85-754707d20a92', 'port': ''}],

          options=None)

          <br>

          *Thread-281877::DEBUG::2013-06-06

          12:36:49,933::misc::84::Storage.Misc.excCmd::(&lt;lambda&gt;)

          '/usr/bin/sudo -n /usr/bin/umount -f -l

          /rhev/data-center/mnt/172.16.0.5:_home_external_migration'

          (cwd None)*

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:50,012::misc::1054::SamplingMethod::(__call__) Trying to

          enter sampling method (storage.sdc.refreshStorage)

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:50,012::misc::1056::SamplingMethod::(__call__) Got in to

          sampling method

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:50,012::misc::1054::SamplingMethod::(__call__) Trying to

          enter sampling method (storage.iscsi.rescan)

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:50,013::misc::1056::SamplingMethod::(__call__) Got in to

          sampling method

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:50,013::misc::84::Storage.Misc.excCmd::(&lt;lambda&gt;)

          '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:50,021::misc::84::Storage.Misc.excCmd::(&lt;lambda&gt;)

          FAILED: &lt;err&gt; = 'iscsiadm: No session found.\n';

          &lt;rc&gt; = 21

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:50,021::misc::1064::SamplingMethod::(__call__) Returning

          last result

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:52,029::misc::84::Storage.Misc.excCmd::(&lt;lambda&gt;)

          '/usr/bin/sudo -n /sbin/multipath' (cwd None)

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:52,188::misc::84::Storage.Misc.excCmd::(&lt;lambda&gt;)

          SUCCESS: &lt;err&gt; = ''; &lt;rc&gt; = 0

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:52,188::lvm::477::OperationMutex::(_invalidateAllPvs)

          Operation 'lvm invalidate operation' got the operation mutex

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:52,189::lvm::479::OperationMutex::(_invalidateAllPvs)

          Operation 'lvm invalidate operation' released the operation

          mutex

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:52,189::lvm::488::OperationMutex::(_invalidateAllVgs)

          Operation 'lvm invalidate operation' got the operation mutex

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:52,189::lvm::490::OperationMutex::(_invalidateAllVgs)

          Operation 'lvm invalidate operation' released the operation

          mutex

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:52,189::lvm::508::OperationMutex::(_invalidateAllLvs)

          Operation 'lvm invalidate operation' got the operation mutex

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:52,189::lvm::510::OperationMutex::(_invalidateAllLvs)

          Operation 'lvm invalidate operation' released the operation

          mutex

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:52,189::misc::1064::SamplingMethod::(__call__) Returning

          last result

          <br>

          Thread-281877::<a class="moz-txt-link-freetext" href="INFO::2013-06-06">INFO::2013-06-06</a>

          12:36:52,189::logUtils::44::dispatcher::(wrapper) Run and

          protect: disconnectStorageServer, Return response:

          {'statuslist': [{'status': 0, 'id':

          '45085cbf-da10-4852-9d85-754707d20a92'}]}

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:52,190::task::1151::TaskManager.Task::(prepare)

          Task=`c0d1c115-cb3d-4f39-8c9b-448401097921`::finished:

          {'statuslist': [{'status': 0, 'id':

          '45085cbf-da10-4852-9d85-754707d20a92'}]}

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:52,190::task::568::TaskManager.Task::(_updateState)

          Task=`c0d1c115-cb3d-4f39-8c9b-448401097921`::moving from state

          preparing -&gt; state finished

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:52,190::resourceManager::830::ResourceManager.Owner::(releaseAll)

          Owner.releaseAll requests {} resources {}

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:52,190::resourceManager::864::ResourceManager.Owner::(cancelAll)

          Owner.cancelAll requests {}

          <br>

          Thread-281877::DEBUG::2013-06-06

          12:36:52,190::task::957::TaskManager.Task::(_decref)

          Task=`c0d1c115-cb3d-4f39-8c9b-448401097921`::ref 0 aborting

          False

          <br>

          VM Channels Listener::DEBUG::2013-06-06

          12:36:55,355::vmChannels::61::vds::(_handle_timeouts) Timeout

          on fileno 31.

          <br>

          Thread-281881::DEBUG::2013-06-06

          12:36:55,705::BindingXMLRPC::161::vds::(wrapper) [172.16.0.5]

          <br>

          Thread-281881::DEBUG::2013-06-06

          12:36:55,706::task::568::TaskManager.Task::(_updateState)

          Task=`da3a8b8e-60ea-4c84-a72c-8feea05c7178`::moving from state

          init -&gt; state preparing

          <br>

          Thread-281881::<a class="moz-txt-link-freetext" href="INFO::2013-06-06">INFO::2013-06-06</a>

          12:36:55,706::logUtils::41::dispatcher::(wrapper) Run and

          protect:

          getSpmStatus(spUUID='d76c9edf-34cb-48eb-b53b-32d27bedc26a',

          options=None)

          <br>

          Thread-281881::<a class="moz-txt-link-freetext" href="INFO::2013-06-06">INFO::2013-06-06</a>

          12:36:55,706::logUtils::44::dispatcher::(wrapper) Run and

          protect: getSpmStatus, Return response: {'spm_st': {'spmId':

          1, 'spmStatus': 'SPM', 'spmLver': 3}}

          <br>

          Thread-281881::DEBUG::2013-06-06

          12:36:55,706::task::1151::TaskManager.Task::(prepare)

          Task=`da3a8b8e-60ea-4c84-a72c-8feea05c7178`::finished:

          {'spm_st': {'spmId': 1, 'spmStatus': 'SPM', 'spmLver': 3}}

          <br>

          Thread-281881::DEBUG::2013-06-06

          12:36:55,706::task::568::TaskManager.Task::(_updateState)

          Task=`da3a8b8e-60ea-4c84-a72c-8feea05c7178`::moving from state

          preparing -&gt; state finished

          <br>

          Thread-281881::DEBUG::2013-06-06

          12:36:55,706::resourceManager::830::ResourceManager.Owner::(releaseAll)

          Owner.releaseAll requests {} resources {}

          <br>

          Thread-281881::DEBUG::2013-06-06

          12:36:55,706::resourceManager::864::ResourceManager.Owner::(cancelAll)

          Owner.cancelAll requests {}

          <br>

          Thread-281881::DEBUG::2013-06-06

          12:36:55,707::task::957::TaskManager.Task::(_decref)

          Task=`da3a8b8e-60ea-4c84-a72c-8feea05c7178`::ref 0 aborting

          False

          <br>

          Thread-281882::DEBUG::2013-06-06

          12:36:55,709::BindingXMLRPC::161::vds::(wrapper) [172.16.0.5]

          <br>

          Thread-281882::DEBUG::2013-06-06

          12:36:55,709::task::568::TaskManager.Task::(_updateState)

          Task=`efc1142e-49bd-4649-8b3d-57e0a408460a`::moving from state

          init -&gt; state preparing

          <br>

          Thread-281882::<a class="moz-txt-link-freetext" href="INFO::2013-06-06">INFO::2013-06-06</a>

          12:36:55,709::logUtils::41::dispatcher::(wrapper) Run and

          protect:

          getStoragePoolInfo(spUUID='d76c9edf-34cb-48eb-b53b-32d27bedc26a',

          options=None)

          <br>

          Thread-281882::DEBUG::2013-06-06

          12:36:55,709::resourceManager::190::ResourceManager.Request::(__init__)

          ResName=`Storage.d76c9edf-34cb-48eb-b53b-32d27bedc26a`ReqID=`9b522d87-e9b5-46ae-932c-c3102d25ef28`::Request

          was made in '/usr/share/vdsm/storage/resourceManager.py' line

          '189' at '__init__'

          <br>

          Thread-281882::DEBUG::2013-06-06

          12:36:55,709::resourceManager::504::ResourceManager::(registerResource)

          Trying to register resource

          'Storage.d76c9edf-34cb-48eb-b53b-32d27bedc26a' for lock type

          'shared'

          <br>

          Thread-281882::DEBUG::2013-06-06

          12:36:55,710::resourceManager::547::ResourceManager::(registerResource)

          Resource 'Storage.d76c9edf-34cb-48eb-b53b-32d27bedc26a' is

          free. Now locking as 'shared' (1 active user)

          <br>

          Thread-281882::DEBUG::2013-06-06

          12:36:55,710::resourceManager::227::ResourceManager.Request::(grant)

          ResName=`Storage.d76c9edf-34cb-48eb-b53b-32d27bedc26a`ReqID=`9b522d87-e9b5-46ae-932c-c3102d25ef28`::Granted

          request

          <br>

          Thread-281882::DEBUG::2013-06-06

          12:36:55,710::task::794::TaskManager.Task::(resourceAcquired)

          Task=`efc1142e-49bd-4649-8b3d-57e0a408460a`::_resourcesAcquired:

          Storage.d76c9edf-34cb-48eb-b53b-32d27bedc26a (shared)

          <br>

          Thread-281882::DEBUG::2013-06-06

          12:36:55,710::task::957::TaskManager.Task::(_decref)

          Task=`efc1142e-49bd-4649-8b3d-57e0a408460a`::ref 1 aborting

          False

          <br>

          Thread-281882::<a class="moz-txt-link-freetext" href="INFO::2013-06-06">INFO::2013-06-06</a>

          12:36:55,711::logUtils::44::dispatcher::(wrapper) Run and

          protect: getStoragePoolInfo, Return response: {'info':

          {'spm_id': 1, 'master_uuid':

          'fb8feb05-b605-4014-ac05-14b0fb1e37e9', 'name': 'nodo1-Local',

          'version': '3', 'domains':

          'fb8feb05-b605-4014-ac05-14b0fb1e37e9:Active,e79cd423-ae17-4f8b-9f53-28d851cc9822:Attached',

          'pool_status': 'connected', 'isoprefix': '', 'type':

          'LOCALFS', 'master_ver': 1, 'lver': 3}, 'dominfo':

          {'fb8feb05-b605-4014-ac05-14b0fb1e37e9': {'status': 'Active',

          'diskfree': '348445036544', 'alerts': [], 'disktotal':

          '492120522752'}, 'e79cd423-ae17-4f8b-9f53-28d851cc9822':

          {'status': 'Attached'}}}

          <br>

          Thread-281882::DEBUG::2013-06-06

          12:36:55,711::task::1151::TaskManager.Task::(prepare)

          Task=`efc1142e-49bd-4649-8b3d-57e0a408460a`::finished:

          {'info': {'spm_id': 1, 'master_uuid':

          'fb8feb05-b605-4014-ac05-14b0fb1e37e9', 'name': 'nodo1-Local',

          'version': '3', 'domains':

          'fb8feb05-b605-4014-ac05-14b0fb1e37e9:Active,e79cd423-ae17-4f8b-9f53-28d851cc9822:Attached',

          'pool_status': 'connected', 'isoprefix': '', 'type':

          'LOCALFS', 'master_ver': 1, 'lver': 3}, 'dominfo':

          {'fb8feb05-b605-4014-ac05-14b0fb1e37e9': {'status': 'Active',

          'diskfree': '348445036544', 'alerts': [], 'disktotal':

          '492120522752'}, 'e79cd423-ae17-4f8b-9f53-28d851cc9822':

          {'status': 'Attached'}}}

          <br>

          Thread-281882::DEBUG::2013-06-06

          12:36:55,711::task::568::TaskManager.Task::(_updateState)

          Task=`efc1142e-49bd-4649-8b3d-57e0a408460a`::moving from state

          preparing -&gt; state finished

          <br>

          Thread-281882::DEBUG::2013-06-06

          12:36:55,711::resourceManager::830::ResourceManager.Owner::(releaseAll)

          Owner.releaseAll requests {} resources

          {'Storage.d76c9edf-34cb-48eb-b53b-32d27bedc26a': &lt;

          ResourceRef 'Storage.d76c9edf-34cb-48eb-b53b-32d27bedc26a',

          isValid: 'True' obj: 'None'&gt;}

          <br>

          Thread-281882::DEBUG::2013-06-06

          12:36:55,711::resourceManager::864::ResourceManager.Owner::(cancelAll)

          Owner.cancelAll requests {}

          <br>

          Thread-281882::DEBUG::2013-06-06

          12:36:55,711::resourceManager::557::ResourceManager::(releaseResource)

          Trying to release resource

          'Storage.d76c9edf-34cb-48eb-b53b-32d27bedc26a'

          <br>

          Thread-281882::DEBUG::2013-06-06

          12:36:55,711::resourceManager::573::ResourceManager::(releaseResource)

          Released resource

          'Storage.d76c9edf-34cb-48eb-b53b-32d27bedc26a' (0 active

          users)

          <br>

          Thread-281882::DEBUG::2013-06-06

          12:36:55,711::resourceManager::578::ResourceManager::(releaseResource)

          Resource 'Storage.d76c9edf-34cb-48eb-b53b-32d27bedc26a' is

          free, finding out if anyone is waiting for it.

          <br>

          Thread-281882::DEBUG::2013-06-06

          12:36:55,712::resourceManager::585::ResourceManager::(releaseResource)

          No one is waiting for resource

          'Storage.d76c9edf-34cb-48eb-b53b-32d27bedc26a', Clearing

          records.

          <br>

          Thread-281882::DEBUG::2013-06-06

          12:36:55,712::task::957::TaskManager.Task::(_decref)

          Task=`efc1142e-49bd-4649-8b3d-57e0a408460a`::ref 0 aborting

          False

          <br>

          Thread-281883::DEBUG::2013-06-06

          12:36:57,645::task::568::TaskManager.Task::(_updateState)

          Task=`9f7eee6f-a85f-4922-a229-300f57133718`::moving from state

          init -&gt; state preparing

          <br>

          Thread-281883::<a class="moz-txt-link-freetext" href="INFO::2013-06-06">INFO::2013-06-06</a>

          12:36:57,645::logUtils::41::dispatcher::(wrapper) Run and

          protect: repoStats(options=None)

          <br>

          Thread-281883::<a class="moz-txt-link-freetext" href="INFO::2013-06-06">INFO::2013-06-06</a>

          12:36:57,645::logUtils::44::dispatcher::(wrapper) Run and

          protect: repoStats, Return response:

          {'fb8feb05-b605-4014-ac05-14b0fb1e37e9': {'delay':

          '0.0230140686035', 'lastCheck': '2.8', 'code': 0, 'valid':

          True}}

          <br>

          Thread-281883::DEBUG::2013-06-06

          12:36:57,645::task::1151::TaskManager.Task::(prepare)

          Task=`9f7eee6f-a85f-4922-a229-300f57133718`::finished:

          {'fb8feb05-b605-4014-ac05-14b0fb1e37e9': {'delay':

          '0.0230140686035', 'lastCheck': '2.8', 'code': 0, 'valid':

          True}}

          <br>

          Thread-281883::DEBUG::2013-06-06

          12:36:57,645::task::568::TaskManager.Task::(_updateState)

          Task=`9f7eee6f-a85f-4922-a229-300f57133718`::moving from state

          preparing -&gt; state finished

          <br>

          Thread-281883::DEBUG::2013-06-06

          12:36:57,646::resourceManager::830::ResourceManager.Owner::(releaseAll)

          Owner.releaseAll requests {} resources {}

          <br>

          Thread-281883::DEBUG::2013-06-06

          12:36:57,646::resourceManager::864::ResourceManager.Owner::(cancelAll)

          Owner.cancelAll requests {}

          <br>

          Thread-281883::DEBUG::2013-06-06

          12:36:57,646::task::957::TaskManager.Task::(_decref)

          Task=`9f7eee6f-a85f-4922-a229-300f57133718`::ref 0 aborting

          False

          <br>

          VM Channels Listener::DEBUG::2013-06-06

          12:36:58,358::vmChannels::61::vds::(_handle_timeouts) Timeout

          on fileno 85.

          <br>

          Thread-281885::DEBUG::2013-06-06

          12:36:58,994::BindingXMLRPC::161::vds::(wrapper) [172.16.0.5]

          <br>

          Thread-281885::DEBUG::2013-06-06

          12:36:58,994::task::568::TaskManager.Task::(_updateState)

          Task=`5b718b7c-415a-4995-b0be-4773d5b2dbad`::moving from state

          init -&gt; state preparing

          <br>

          Thread-281885::<a class="moz-txt-link-freetext" href="INFO::2013-06-06">INFO::2013-06-06</a>

          12:36:58,994::logUtils::41::dispatcher::(wrapper) Run and

          protect: validateStorageServerConnection(domType=1,

          spUUID='00000000-0000-0000-0000-000000000000',

          conList=[{'connection': '172.16.0.5:/home/external/migration',

          'iqn': '', 'portal': '', 'user': '', 'password': '******',

          'id': '45085cbf-da10-4852-9d85-754707d20a92', 'port': ''}],

          options=None)

          <br>

          Thread-281885::<a class="moz-txt-link-freetext" href="INFO::2013-06-06">INFO::2013-06-06</a>

          12:36:58,994::logUtils::44::dispatcher::(wrapper) Run and

          protect: validateStorageServerConnection, Return response:

          {'statuslist': [{'status': 0, 'id':

          '45085cbf-da10-4852-9d85-754707d20a92'}]}

          <br>

          Thread-281885::DEBUG::2013-06-06

          12:36:58,994::task::1151::TaskManager.Task::(prepare)

          Task=`5b718b7c-415a-4995-b0be-4773d5b2dbad`::finished:

          {'statuslist': [{'status': 0, 'id':

          '45085cbf-da10-4852-9d85-754707d20a92'}]}

          <br>

          Thread-281885::DEBUG::2013-06-06

          12:36:58,995::task::568::TaskManager.Task::(_updateState)

          Task=`5b718b7c-415a-4995-b0be-4773d5b2dbad`::moving from state

          preparing -&gt; state finished

          <br>

          <br>

          And here is the engine part:

          <br>

          <br>

          2013-06-06 12:35:45,693 INFO

          [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]

          (pool-3-thread-50) START, HSMClearTaskVDSCommand(HostName =

          nodo1, HostId = 3156bdac-ebfb-44cf-bea6-53d668b74a10,

          taskId=6592e0f7-4df3-404c-b1c4-6e95715453ef), log id: 4356a978

          <br>

          2013-06-06 12:35:45,696 INFO

          [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]

          (pool-3-thread-50) FINISH, HSMClearTaskVDSCommand, log id:

          4356a978

          <br>

          2013-06-06 12:35:45,697 INFO

          [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand]

          (pool-3-thread-50) FINISH, SPMClearTaskVDSCommand, log id:

          121e765

          <br>

          2013-06-06 12:35:45,708 INFO

          [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-3-thread-50)

          BaseAsyncTask::RemoveTaskFromDB: Removed task

          6592e0f7-4df3-404c-b1c4-6e95715453ef from DataBase

          <br>

          2013-06-06 12:35:45,708 INFO

          [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-50)

          EntityAsyncTask::HandleEndActionResult [within thread]:

          Removing EntityMultiAsyncTasks object for entity

          2518c791-17fc-413e-a353-8437b6fcf478

          <br>

          2013-06-06 12:36:03,193 INFO

          [org.ovirt.engine.core.bll.LoginUserCommand]

          (ajp--127.0.0.1-8702-5) Running command: LoginUserCommand

          internal: false.

          <br>

          2013-06-06 12:36:03,225 WARN

          [org.ovirt.engine.core.bll.GetConfigurationValueQuery]

          (ajp--127.0.0.1-8702-5) calling GetConfigurationValueQuery

          (ApplicationMode) with null version, using default general for

          version

          <br>

          2013-06-06 12:36:03,225 WARN

          [org.ovirt.engine.core.bll.GetConfigurationValueQuery]

          (ajp--127.0.0.1-8702-5) calling GetConfigurationValueQuery

          (VdcVersion) with null version, using default general for

          version

          <br>

          2013-06-06 12:36:47,337 INFO

          [org.ovirt.engine.core.bll.storage.DeactivateStorageDomainCommand]

          (ajp--127.0.0.1-8702-5) Lock Acquired to object EngineLock

          [exclusiveLocks= key: e79cd423-ae17-4f8b-9f53-28d851cc9822

          value: STORAGE

          <br>

          , sharedLocks= ]

          <br>

          2013-06-06 12:36:47,386 INFO

          [org.ovirt.engine.core.bll.storage.DeactivateStorageDomainCommand]

          (pool-3-thread-50) [787573d0] Running command:

          DeactivateStorageDomainCommand internal: false. Entities

          affected :  ID: e79cd423-ae17-4f8b-9f53-28d851cc9822 Type:

          Storage

          <br>

          2013-06-06 12:36:47,394 INFO

          [org.ovirt.engine.core.vdsbroker.irsbroker.DeactivateStorageDomainVDSCommand]

          (pool-3-thread-50) [787573d0] START,

          DeactivateStorageDomainVDSCommand( storagePoolId =

          d76c9edf-34cb-48eb-b53b-32d27bedc26a, ignoreFailoverLimit =

          false, compatabilityVersion = null, storageDomainId =

          e79cd423-ae17-4f8b-9f53-28d851cc9822, masterDomainId =

          00000000-0000-0000-0000-000000000000, masterVersion = 1), log

          id: 94abeb9

          <br>

          2013-06-06 12:36:47,406 INFO

          [org.ovirt.engine.core.vdsbroker.irsbroker.DeactivateStorageDomainVDSCommand]

          (pool-3-thread-50) [787573d0] FINISH,

          DeactivateStorageDomainVDSCommand, log id: 94abeb9

          <br>

          2013-06-06 12:36:47,406 INFO

          [org.ovirt.engine.core.bll.storage.DeactivateStorageDomainCommand]

          (pool-3-thread-50) [787573d0] Lock freed to object EngineLock

          [exclusiveLocks= key: e79cd423-ae17-4f8b-9f53-28d851cc9822

          value: STORAGE

          <br>

          , sharedLocks= ]

          <br>

          2013-06-06 12:36:47,409 INFO

          [org.ovirt.engine.core.bll.storage.AfterDeactivateSingleAsyncOperation]

          (pool-3-thread-47) [787573d0] After deactivate treatment vds:

          nodo1,pool nodo1-Local

          <br>

          2013-06-06 12:36:47,412 INFO

          [org.ovirt.engine.core.vdsbroker.vdsbroker.RefreshStoragePoolVDSCommand]

          (pool-3-thread-47) [787573d0] START,

          RefreshStoragePoolVDSCommand(HostName = nodo1, HostId =

          3156bdac-ebfb-44cf-bea6-53d668b74a10, storagePoolId =

          d76c9edf-34cb-48eb-b53b-32d27bedc26a,

          masterStorageDomainId=fb8feb05-b605-4014-ac05-14b0fb1e37e9,

          msterVersion=1), log id: 2ca9a709

          <br>

          2013-06-06 12:36:49,927 INFO

          [org.ovirt.engine.core.vdsbroker.vdsbroker.RefreshStoragePoolVDSCommand]

          (pool-3-thread-47) [787573d0] FINISH,

          RefreshStoragePoolVDSCommand, log id: 2ca9a709

          <br>

          2013-06-06 12:36:49,929 INFO

          [org.ovirt.engine.core.bll.storage.RemoveStorageServerConnectionCommand]

          (pool-3-thread-50) [3bf3ce09] Running command:

          RemoveStorageServerConnectionCommand internal: true. Entities

          affected :  ID: aaa00000-0000-0000-0000-123456789aaa Type:

          System

          <br>

          2013-06-06 12:36:49,931 INFO

          [org.ovirt.engine.core.vdsbroker.vdsbroker.DisconnectStorageServerVDSCommand]

          (pool-3-thread-50) [3bf3ce09] START,

          DisconnectStorageServerVDSCommand(HostName = nodo1, HostId =

          3156bdac-ebfb-44cf-bea6-53d668b74a10, storagePoolId =

          00000000-0000-0000-0000-000000000000, storageType = NFS,

          connectionList = [{ id: 45085cbf-da10-4852-9d85-754707d20a92,

          connection: 172.16.0.5:/home/external/migration, iqn: null,

          vfsType: null, mountOptions: null, nfsVersion: null,

          nfsRetrans: null, nfsTimeo: null };]), log id: ae4d339

          <br>

          2013-06-06 12:36:50,809 INFO

          [org.ovirt.engine.core.bll.AsyncTaskManager]

          (DefaultQuartzScheduler_Worker-9) Setting new tasks map. The

          map contains now 0 tasks

          <br>

          2013-06-06 12:36:50,809 INFO

          [org.ovirt.engine.core.bll.AsyncTaskManager]

          (DefaultQuartzScheduler_Worker-9) Cleared all tasks of pool

          d76c9edf-34cb-48eb-b53b-32d27bedc26a.

          <br>

          2013-06-06 12:36:50,811 INFO

          [org.ovirt.engine.core.bll.AsyncTaskManager]

          (DefaultQuartzScheduler_Worker-9) Could not find vds that is

          spm and non-operational.

          <br>

          2013-06-06 12:36:52,193 INFO

          [org.ovirt.engine.core.vdsbroker.vdsbroker.DisconnectStorageServerVDSCommand]

          (pool-3-thread-50) [3bf3ce09] FINISH,

          DisconnectStorageServerVDSCommand, return:

          {45085cbf-da10-4852-9d85-754707d20a92=0}, log id: ae4d339

          <br>

          2013-06-06 12:36:58,978 INFO

          [org.ovirt.engine.core.bll.storage.DetachStorageDomainFromPoolCommand]

          (pool-3-thread-50) [65c04a25] Running command:

          DetachStorageDomainFromPoolCommand internal: false. Entities

          affected :  ID: e79cd423-ae17-4f8b-9f53-28d851cc9822 Type:

          Storage

          <br>

          2013-06-06 12:36:58,978 INFO

          [org.ovirt.engine.core.bll.storage.DetachStorageDomainFromPoolCommand]

          (pool-3-thread-50) [65c04a25] Start detach storage domain

          <br>

          2013-06-06 12:36:58,986 INFO

          [org.ovirt.engine.core.bll.storage.DetachStorageDomainFromPoolCommand]

          (pool-3-thread-50) [65c04a25]  Detach storage domain: before

          connect

          <br>

          2013-06-06 12:36:58,992 INFO

          [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand]

          (pool-3-thread-47) [7345dde6] START,

          ValidateStorageServerConnectionVDSCommand(HostName = nodo1,

          HostId = 3156bdac-ebfb-44cf-bea6-53d668b74a10, storagePoolId =

          00000000-0000-0000-0000-000000000000, storageType = NFS,

          connectionList = [{ id: 45085cbf-da10-4852-9d85-754707d20a92,

          connection: 172.16.0.5:/home/external/migration, iqn: null,

          vfsType: null, mountOptions: null, nfsVersion: null,

          nfsRetrans: null, nfsTimeo: null };]), log id: 313568f0

          <br>

          2013-06-06 12:36:58,997 INFO

          [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand]

          (pool-3-thread-47) [7345dde6] FINISH,

          ValidateStorageServerConnectionVDSCommand, return:

          {45085cbf-da10-4852-9d85-754707d20a92=0}, log id: 313568f0

          <br>

          2013-06-06 12:36:58,998 INFO

          [org.ovirt.engine.core.bll.storage.ConnectStorageToVdsCommand]

          (pool-3-thread-47) [7345dde6] Running command:

          ConnectStorageToVdsCommand internal: true. Entities affected :

          ID: aaa00000-0000-0000-0000-123456789aaa Type: System

          <br>

          2013-06-06 12:36:58,999 INFO

          [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand]

          (pool-3-thread-47) [7345dde6] START,

          ConnectStorageServerVDSCommand(HostName = nodo1, HostId =

          3156bdac-ebfb-44cf-bea6-53d668b74a10, storagePoolId =

          00000000-0000-0000-0000-000000000000, storageType = NFS,

          connectionList = [{ id: 45085cbf-da10-4852-9d85-754707d20a92,

          connection: 172.16.0.5:/home/external/migration, iqn: null,

          vfsType: null, mountOptions: null, nfsVersion: null,

          nfsRetrans: null, nfsTimeo: null };]), log id: 54464e6b

          <br>

          2013-06-06 12:36:59,149 INFO

          [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand]

          (pool-3-thread-47) [7345dde6] FINISH,

          ConnectStorageServerVDSCommand, return:

          {45085cbf-da10-4852-9d85-754707d20a92=100}, log id: 54464e6b

          <br>

          2013-06-06 12:36:59,150 ERROR

          [org.ovirt.engine.core.bll.storage.NFSStorageHelper]

          (pool-3-thread-47) [7345dde6] The connection with details

          172.16.0.5:/home/external/migration failed because of error

          code 100 and error message is: generalexception

          <br>

          2013-06-06 12:36:59,175 ERROR

          [org.ovirt.engine.core.bll.storage.ConnectStorageToVdsCommand]

          (pool-3-thread-47) [7345dde6] Transaction rolled-back for

          command: