<div dir="ltr">Thank you for the fast reply and help. <br></div><div class="gmail_extra"><br><div class="gmail_quote">On Thu, Mar 15, 2018 at 8:21 PM, Dominik Holler <span dir="ltr"><<a href="mailto:dholler@redhat.com" target="_blank">dholler@redhat.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><span class="">On Thu, 15 Mar 2018 16:24:10 +0000<br>
Dafna Ron <<a href="mailto:dron@redhat.com">dron@redhat.com</a>> wrote:<br>
<br>
> Hi,<br>
><br>
> We have a failure on master for test<br>
> 098_ovirt_provider_ovn.use_<wbr>ovn_provider in project cockpit-ovirt.<br>
> This seems to be a race because object is locked. also, the actual<br>
> failure is logged as WARN and not ERROR.<br>
><br>
> I don't think the patch is actually related to the failure but I<br>
> think the test should be fixed.<br>
> can you please review to make sure we do not have an actual<br>
> regression and let me know if we need to open a bz to fix the test?<br>
><br>
><br>
</span>> *Link and headline of suspected patches: *<br>
> *<a href="https://gerrit.ovirt.org/#/c/89020/2" rel="noreferrer" target="_blank">https://gerrit.ovirt.org/#/c/<wbr>89020/2</a><br>
> <<a href="https://gerrit.ovirt.org/#/c/89020/2" rel="noreferrer" target="_blank">https://gerrit.ovirt.org/#/c/<wbr>89020/2</a>> - *<br>
><br>
><br>
><br>
><br>
><br>
><br>
><br>
><br>
><br>
><br>
><br>
><br>
><br>
><br>
><br>
><br>
><br>
><br>
><br>
><br>
><br>
><br>
><br>
><br>
><br>
><br>
> *wizard: Enable scroll on start page for low-res screensLink to<br>
<span class="">> Job:<a href="http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/6374" rel="noreferrer" target="_blank">http://jenkins.ovirt.org/<wbr>job/ovirt-master_change-queue-<wbr>tester/6374</a><br>
> <<a href="http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/6374" rel="noreferrer" target="_blank">http://jenkins.ovirt.org/job/<wbr>ovirt-master_change-queue-<wbr>tester/6374</a>>Link<br>
> to all<br>
> logs:<a href="http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/6374/artifacts" rel="noreferrer" target="_blank">http://jenkins.ovirt.org/<wbr>job/ovirt-master_change-queue-<wbr>tester/6374/artifacts</a><br>
> <<a href="http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/6374/artifacts" rel="noreferrer" target="_blank">http://jenkins.ovirt.org/job/<wbr>ovirt-master_change-queue-<wbr>tester/6374/artifacts</a>>(<wbr>Relevant)<br>
> error snippet from the log: <error>2018-03-15 10:05:00,160-04 DEBUG<br>
> [org.ovirt.engine.core.sso.<wbr>servlets.<wbr>OAuthTokenInfoServlet] (default<br>
</span>> task-10) [] Sending json response2018-03-15 10:05:00,160-04 DEBUG<br>
> [org.ovirt.engine.core.sso.<wbr>utils.TokenCleanupUtility] (default<br>
> task-10) [] Not cleaning up expired tokens2018-03-15 10:05:00,169-04<br>
<span class="">> INFO<br>
> [org.ovirt.engine.core.bll.<wbr>provider.network.<wbr>SyncNetworkProviderCommand]<br>
> (EE-ManagedThreadFactory-<wbr>engineScheduled-Thread-90) [789edb23] Lock<br>
> Acquired to object<br>
</span>> 'EngineLock:{exclusiveLocks='[<wbr>c38a67ec-0b48-4e6f-be85-<wbr>70c700df5483=PROVIDER]',<br>
> sharedLocks=''}'2018-03-15 10:05:00,184-04 INFO<br>
<span class="">> [org.ovirt.engine.core.bll.<wbr>provider.network.<wbr>SyncNetworkProviderCommand]<br>
> (EE-ManagedThreadFactory-<wbr>engineScheduled-Thread-90) [789edb23]<br>
> Running command: SyncNetworkProviderCommand internal: true.2018-03-15<br>
> 10:05:00,228-04 DEBUG<br>
> [org.ovirt.engine.core.dal.<wbr>dbbroker.<wbr>PostgresDbEngineDialect$<wbr>PostgresSimpleJdbcCall]<br>
> (default task-13) [e1328379-17b7-49f8-beb2-<wbr>cf8331784828] Compiled<br>
> stored procedure. Call string is [{call<br>
</span>> getdcidbyexternalnetworkid(?)}<wbr>]2018-03-15 10:05:00,228-04 DEBUG<br>
<span class="">> [org.ovirt.engine.core.dal.<wbr>dbbroker.<wbr>PostgresDbEngineDialect$<wbr>PostgresSimpleJdbcCall]<br>
> (default task-13) [e1328379-17b7-49f8-beb2-<wbr>cf8331784828] SqlCall for<br>
> procedure [GetDcIdByExternalNetworkId] compiled2018-03-15<br>
> 10:05:00,229-04 DEBUG<br>
> [org.ovirt.engine.core.common.<wbr>di.interceptor.<wbr>DebugLoggingInterceptor]<br>
> (default task-13) [e1328379-17b7-49f8-beb2-<wbr>cf8331784828] method:<br>
> runQuery, params: [<wbr>GetAllExternalNetworksOnProvid<wbr>er,<br>
> IdQueryParameters:{refresh='<wbr>false', filtered='false'}], timeElapsed:<br>
</span>> 353ms2018-03-15 10:05:00,239-04 INFO<br>
<span class="">> [org.ovirt.engine.core.bll.<wbr>network.dc.AddNetworkCommand] (default<br>
> task-13) [e1328379-17b7-49f8-beb2-<wbr>cf8331784828] Failed to Acquire<br>
> Lock to object 'EngineLock:{exclusiveLocks='[<wbr>network_1=NETWORK,<br>
> c38a67ec-0b48-4e6f-be85-<wbr>70c700df5483=PROVIDER]',<br>
> sharedLocks=''}'2018-03-15 10:05:00,239-04 WARN<br>
> [org.ovirt.engine.core.bll.<wbr>network.dc.AddNetworkCommand] (default<br>
> task-13) [e1328379-17b7-49f8-beb2-<wbr>cf8331784828] Validation of action<br>
> 'AddNetwork' failed for user admin@internal-authz. Reasons:<br>
> VAR__TYPE__NETWORK,VAR__<wbr>ACTION__ADD,ACTION_TYPE_<wbr>FAILED_PROVIDER_LOCKED,$<wbr>providerId<br>
</span>> c38a67ec-0b48-4e6f-be85-<wbr>70c700df54832018-03-15 10:05:00,240-04 DEBUG<br>
<span class="">> [org.ovirt.engine.core.common.<wbr>di.interceptor.<wbr>DebugLoggingInterceptor]<br>
> (default task-13) [e1328379-17b7-49f8-beb2-<wbr>cf8331784828] method:<br>
> runAction, params: [AddNetwork,<br>
> AddNetworkStoragePoolParameter<wbr>s:{commandId='61b365ec-27c1-<wbr>49af-ad72-f907df8befcd',<br>
> user='null', commandType='Unknown'}], timeElapsed: 10ms2018-03-15<br>
> 10:05:00,250-04 ERROR<br>
> [org.ovirt.engine.api.restapi.<wbr>resource.<wbr>AbstractBackendResource]<br>
> (default task-13) [] Operation Failed: [Cannot add Network. Related<br>
> operation on provider with the id<br>
> c38a67ec-0b48-4e6f-be85-<wbr>70c700df5483 is currently in progress. Please<br>
> try again later.]2018-03-15 10:05:00,254-04 DEBUG<br>
> [org.ovirt.engine.core.utils.<wbr>servlet.LocaleFilter] (default task-14)<br>
> [] Incoming locale 'en-US'. Filter determined locale to be<br>
> 'en-US'2018-03-15 10:05:00,254-04 DEBUG<br>
> [org.ovirt.engine.core.sso.<wbr>servlets.OAuthTokenServlet] (default<br>
> task-14) [] Entered OAuthTokenServlet Query String: null,<br>
> Parameters : password = ***, grant_type = password, scope =<br>
> ovirt-app-api ovirt-ext=token-info:validate, username =<br>
</span>> admin@internal, </error>*<br>
<br>
I will care about this.<br>
The problem is that SyncNetworkProviderCommand is running in the<br>
background and locking the provider, which blocks the lock for the<br>
tested AddNetworkCommand.<br>
The related changes are<br>
core: Add locking for Add and RemoveNetworkCommand<br>
<a href="https://gerrit.ovirt.org/#/c/85480/" rel="noreferrer" target="_blank">https://gerrit.ovirt.org/#/c/<wbr>85480/</a><br>
and<br>
core: Add SyncNetworkProviderCommand<br>
<a href="https://gerrit.ovirt.org/#/c/85134/" rel="noreferrer" target="_blank">https://gerrit.ovirt.org/#/c/<wbr>85134/</a><br>
<br>
<br>
</blockquote></div><br></div>