<div dir="ltr"><div><div><div>Hi,<br></div>There is a new failure on on master in experimental flow, the failing test is &#39;add_secondary_storage_domain&#39;, the engine.log has few exceptions:<br><br>2017-01-09 10:07:24,943-05 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.PollVDSCommand] (org.ovirt.thread.pool-6-thread-2) [e9e4e3b] Command &#39;PollVDSCommand(HostName = lago-basic-suite-master-host1, VdsIdVDSCommandParametersBase:{runAsync=&#39;true&#39;, hostId=&#39;f6ad90f7-1b37-49f0-a958-7151efa0039c&#39;})&#39; execution failed: VDSGenericException: VDSNetworkException: Timeout during rpc call<br>2017-01-09 10:07:24,943-05 DEBUG [org.ovirt.engine.core.vdsbroker.vdsbroker.PollVDSCommand] (org.ovirt.thread.pool-6-thread-2) [e9e4e3b] Exception: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSNetworkException: VDSGenericException: VDSNetworkException: Timeout during rpc call<br>        at org.ovirt.engine.core.vdsbroker.vdsbroker.FutureVDSCommand.get(FutureVDSCommand.java:73) [vdsbroker.jar:]<br>...<br>2017-01-09 10:10:23,323-05 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand] (DefaultQuartzScheduler10) [7cad9211] Command &#39;GetAllVmStatsVDSCommand(HostName = lago-basic-suite-master-host1, VdsIdVDSCommandParametersBase:{runAsync=&#39;true&#39;, hostId=&#39;f6ad90f7-1b37-49f0-a958-7151efa0039c&#39;})&#39; execution failed: VDSGenericException: VDSNetworkException: Heartbeat exceeded<br>2017-01-09 10:10:23,323-05 DEBUG [org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand] (DefaultQuartzScheduler10) [7cad9211] Exception: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSNetworkException: VDSGenericException: VDSNetworkException: Heartbeat exceeded<br>        at org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.proceedProxyReturnValue(BrokerCommandBase.java:188) [vdsbroker.jar:]<br>...<br>2017-01-09 10:10:43,704-05 DEBUG [org.ovirt.vdsm.jsonrpc.client.internal.ResponseWorker] (ResponseWorker) [] Illegal unquoted character ((CTRL-CHAR, code 10)): has to be escaped using backslash to be included in name<br> at [Source: [B@6a84a0d0; line: 1, column: 889]: org.codehaus.jackson.JsonParseException: Illegal unquoted character ((CTRL-CHAR, code 10)): has to be escaped using backslash to be included in name<br> at [Source: [B@6a84a0d0; line: 1, column: 889]<br>        at org.codehaus.jackson.JsonParser._constructError(JsonParser.java:1433) [jackson-core-asl-1.9.13.jar:1.9.13]<br>        at org.codehaus.jackson.impl.JsonParserMinimalBase._reportError(JsonParserMinimalBase.java:521) [jackson-core-asl-1.9.13.jar:1.9.13]<br>        at org.codehaus.jackson.impl.JsonParserMinimalBase._throwUnquotedSpace(JsonParserMinimalBase.java:482) [jackson-core-asl-1.9.13.jar:1.9.13]<br>        at org.codehaus.jackson.impl.ReaderBasedParser._parseFieldName2(ReaderBasedParser.java:1042) [jackson-core-asl-1.9.13.jar:1.9.13]<br>        at org.codehaus.jackson.impl.ReaderBasedParser._parseFieldName(ReaderBasedParser.java:1008) [jackson-core-asl-1.9.13.jar:1.9.13]<br>....<br><br><br>&lt;JsonRpcRequest id: &quot;7711f770-dbef-44be-9f9e-2d8a2bfae937&quot;, method: Host.getAllVmStats, params: {}&gt;<br>2017-01-09 10:11:33,336-05 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand] (DefaultQuartzScheduler7) [7cad9211] Command &#39;GetAllVmStatsVDSCommand(HostName = lago-basic-suite-master-host1, VdsIdVDSCommandParameters<br>Base:{runAsync=&#39;true&#39;, hostId=&#39;f6ad90f7-1b37-49f0-a958-7151efa0039c&#39;})&#39; execution failed: VDSGenericException: VDSNetworkException: Unrecognized message received <br>2017-01-09 10:11:33,336-05 DEBUG [org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand] (DefaultQuartzScheduler7) [7cad9211] Exception: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSNetworkException: VDSGenericException: VDSNe<br>tworkException: Unrecognized message received <br>        at org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.proceedProxyReturnValue(BrokerCommandBase.java:188) [vdsbroker.jar:]<br>        at org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand.executeVdsBrokerCommand(GetAllVmStatsVDSCommand.java:23) [vdsbroker.jar:]<br></div><div><br><br><br>VDSM logs on host1:<br></div><div><br>2017-01-09 10:11:27,120 ERROR (jsonrpc/4) [storage.StorageDomainCache] domain 80985016-bdd8-4778-abd9-becc8fedcab4 not found (sdc:157)<br>Traceback (most recent call last):<br>  File &quot;/usr/share/vdsm/storage/sdc.py&quot;, line 155, in _findDomain<br>    dom = findMethod(sdUUID)<br>  File &quot;/usr/share/vdsm/storage/sdc.py&quot;, line 185, in _findUnfetchedDomain<br>    raise se.StorageDomainDoesNotExist(sdUUID)<br>StorageDomainDoesNotExist: Storage domain does not exist: (u&#39;80985016-bdd8-4778-abd9-becc8fedcab4&#39;,)<br>2017-01-09 10:11:27,452 ERROR (jsonrpc/4) [storage.StorageDomainCache] looking for unfetched domain 80985016-bdd8-4778-abd9-becc8fedcab4 (sdc:151)<br>2017-01-09 10:11:27,453 ERROR (jsonrpc/4) [storage.StorageDomainCache] looking for domain 80985016-bdd8-4778-abd9-becc8fedcab4 (sdc:168)<br>2017-01-09 10:11:27,552 WARN  (jsonrpc/4) [storage.LVM] lvm vgs failed: 5 [] [&#39;  WARNING: Not using lvmetad because config setting use_lvmetad=0.&#39;, &#39;  WARNING: To avoid corruption, rescan devices to make changes visible (pvscan --cache).&#39;<br>, &#39;  Volume group &quot;80985016-bdd8-4778-abd9-becc8fedcab4&quot; not found&#39;, &#39;  Cannot process volume group 80985016-bdd8-4778-abd9-becc8fedcab4&#39;] (lvm:377)<br>2017-01-09 10:11:27,559 ERROR (jsonrpc/4) [storage.StorageDomainCache] domain 80985016-bdd8-4778-abd9-becc8fedcab4 not found (sdc:157)<br>Traceback (most recent call last):<br>  File &quot;/usr/share/vdsm/storage/sdc.py&quot;, line 155, in _findDomain<br>    dom = findMethod(sdUUID)<br>  File &quot;/usr/share/vdsm/storage/sdc.py&quot;, line 185, in _findUnfetchedDomain<br>    raise se.StorageDomainDoesNotExist(sdUUID)<br>StorageDomainDoesNotExist: Storage domain does not exist: (u&#39;80985016-bdd8-4778-abd9-becc8fedcab4&#39;,)<br>2017-01-09 10:11:27,560 ERROR (jsonrpc/4) [storage.TaskManager.Task] (Task=&#39;e2381f1f-eee5-4922-a56d-f6ca40d76eec&#39;) Unexpected error (task:870)<br>Traceback (most recent call last):<br>  File &quot;/usr/share/vdsm/storage/task.py&quot;, line 877, in _run<br>    return fn(*args, **kargs)<br>  File &quot;/usr/lib/python2.7/site-packages/vdsm/logUtils.py&quot;, line 50, in wrapper<br>    res = f(*args, **kwargs)<br>  File &quot;/usr/share/vdsm/storage/hsm.py&quot;, line 1159, in attachStorageDomain<br>    pool.attachSD(sdUUID)<br>  File &quot;/usr/lib/python2.7/site-packages/vdsm/storage/securable.py&quot;, line 79, in wrapper<br>    return method(self, *args, **kwargs)<br>  File &quot;/usr/share/vdsm/storage/sp.py&quot;, line 924, in attachSD<br>    dom = sdCache.produce(sdUUID)<br>  File &quot;/usr/share/vdsm/storage/sdc.py&quot;, line 112, in produce<br>    domain.getRealDomain()<br>  File &quot;/usr/share/vdsm/storage/sdc.py&quot;, line 53, in getRealDomain<br>    return self._cache._realProduce(self._sdUUID)<br>  File &quot;/usr/share/vdsm/storage/sdc.py&quot;, line 136, in _realProduce<br>    domain = self._findDomain(sdUUID)<br>  File &quot;/usr/share/vdsm/storage/sdc.py&quot;, line 155, in _findDomain<br>    dom = findMethod(sdUUID)<br>  File &quot;/usr/share/vdsm/storage/sdc.py&quot;, line 185, in _findUnfetchedDomain<br>    raise se.StorageDomainDoesNotExist(sdUUID)<br>StorageDomainDoesNotExist: Storage domain does not exist: (u&#39;80985016-bdd8-4778-abd9-becc8fedcab4&#39;,)<br>....<br>2017-01-09 10:19:31,467 ERROR (jsonrpc/6) [storage.TaskManager.Task] (Task=&#39;700015ba-4aed-4eaf-961b-5a4373b2d4d7&#39;) Unexpected error (task:870)<br>Traceback (most recent call last):<br>  File &quot;/usr/share/vdsm/storage/task.py&quot;, line 877, in _run<br>    return fn(*args, **kargs)<br>  File &quot;/usr/lib/python2.7/site-packages/vdsm/logUtils.py&quot;, line 50, in wrapper<br>    res = f(*args, **kwargs)<br>  File &quot;/usr/share/vdsm/storage/hsm.py&quot;, line 2212, in getAllTasksInfo<br>    raise se.SpmStatusError()<br>SpmStatusError: Not SPM: ()<br>2017-01-09 10:19:31,471 INFO  (jsonrpc/6) [storage.TaskManager.Task] (Task=&#39;700015ba-4aed-4eaf-961b-5a4373b2d4d7&#39;) aborting: Task is aborted: &#39;Not SPM&#39; - code 654 (task:1175)<br>2017-01-09 10:19:31,471 ERROR (jsonrpc/6) [storage.Dispatcher] {&#39;status&#39;: {&#39;message&#39;: &#39;Not SPM: ()&#39;, &#39;code&#39;: 654}} (dispatcher:77)<br>2017-01-09 10:19:31,472 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call Host.getAllTasksInfo failed (error 654) in 0.01 seconds (__init__:515)<br>2017-01-09 10:19:31,479 INFO  (jsonrpc/7) [dispatcher] Run and protect: getAllTasksStatuses(spUUID=None, options=None) (logUtils:49)<br>2017-01-09 10:19:31,479 ERROR (jsonrpc/7) [storage.TaskManager.Task] (Task=&#39;2841da07-b3b4-4573-ae38-b1500f793221&#39;) Unexpected error (task:870)<br>Traceback (most recent call last):<br>  File &quot;/usr/share/vdsm/storage/task.py&quot;, line 877, in _run<br>    return fn(*args, **kargs)<br>  File &quot;/usr/lib/python2.7/site-packages/vdsm/logUtils.py&quot;, line 50, in wrapper<br>    res = f(*args, **kwargs)<br>  File &quot;/usr/share/vdsm/storage/hsm.py&quot;, line 2172, in getAllTasksStatuses<br>    raise se.SpmStatusError()<br>SpmStatusError: Not SPM: ()<br>2017-01-09 10:19:31,480 INFO  (jsonrpc/7) [storage.TaskManager.Task] (Task=&#39;2841da07-b3b4-4573-ae38-b1500f793221&#39;) aborting: Task is aborted: &#39;Not SPM&#39; - code 654 (task:1175)<br><br></div><div><br>Full engine logs can be found here:<br></div><a href="http://jenkins.ovirt.org/job/test-repo_ovirt_experimental_master/4643/artifact/exported-artifacts/basic_suite_master.sh-el7/exported-artifacts/test_logs/basic-suite-master/post-002_bootstrap.py/lago-basic-suite-master-engine/_var_log_ovirt-engine/engine.log">http://jenkins.ovirt.org/job/test-repo_ovirt_experimental_master/4643/artifact/exported-artifacts/basic_suite_master.sh-el7/exported-artifacts/test_logs/basic-suite-master/post-002_bootstrap.py/lago-basic-suite-master-engine/_var_log_ovirt-engine/engine.log</a><br></div><div>VDSM host1 logs:<br><a href="http://jenkins.ovirt.org/job/test-repo_ovirt_experimental_master/4643/artifact/exported-artifacts/basic_suite_master.sh-el7/exported-artifacts/test_logs/basic-suite-master/post-002_bootstrap.py/lago-basic-suite-master-host1/_var_log_vdsm/vdsm.log">http://jenkins.ovirt.org/job/test-repo_ovirt_experimental_master/4643/artifact/exported-artifacts/basic_suite_master.sh-el7/exported-artifacts/test_logs/basic-suite-master/post-002_bootstrap.py/lago-basic-suite-master-host1/_var_log_vdsm/vdsm.log</a><br></div><div>Rest of the logs:<br><a href="http://jenkins.ovirt.org/job/test-repo_ovirt_experimental_master/4643/artifact/exported-artifacts/basic_suite_master.sh-el7/exported-artifacts/test_logs/basic-suite-master/post-002_bootstrap.py/">http://jenkins.ovirt.org/job/test-repo_ovirt_experimental_master/4643/artifact/exported-artifacts/basic_suite_master.sh-el7/exported-artifacts/test_logs/basic-suite-master/post-002_bootstrap.py/</a><br><br><br></div><div>Could someone take a look?<br><br><br></div><div>Thanks,<br><br></div><div>Nadav.<br><br></div><div><br></div><br><div><div><br><br></div></div></div>