[
https://ovirt-jira.atlassian.net/browse/OVIRT-2148?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=36906#comment-36906
]
Dafna Ron edited comment on OVIRT-2148 at 6/7/18 9:12 AM:
----------------------------------------------------------
This is a race inside engine when a command is sent for a locked object.
here you can see that the lock was taken, another attempt to take the lock was
made and failed. then the lock was released
'018-06-06 10:25:50,334-04 INFO
[org.ovirt.engine.core.bll.RefreshHostCapabilitiesCommand]
(ForkJoinPool-1-worker-15) [2180968c] Lock Acquired to object
'EngineLock:{exclusiveLocks='[HOST_NETWORKf44822d4-7967-44fb-b59e-23e73c7ba33c=HOST_
NETWORK, f44822d4-7967-44fb-b59e-23e73c7ba33c=VDS]', sharedLocks=''}'
2018-06-06 10:25:50,338-04 DEBUG
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor]
(ForkJoinPool-1-worker-15) [2180968c] method: get, params:
[f44822d4-7967-44fb-b59e-23e73c7ba33c], timeElapsed: 4ms
2018-06-06 10:25:50,341-04 INFO
[org.ovirt.engine.core.bll.RefreshHostCapabilitiesCommand]
(ForkJoinPool-1-worker-15) [2180968c] Running command:
RefreshHostCapabilitiesCommand internal: true. Entities affected : ID:
f44822d4-7967-44fb-
b59e-23e73c7ba33c Type: VDSAction group MANIPULATE_HOST with role type ADMIN
2018-06-06 10:25:50,341-04 DEBUG
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor]
(ForkJoinPool-1-worker-15) [2180968c] method: getVdsManager, params:
[f44822d4-7967-44fb-b59e-23e73c7ba33c], timeElapsed: 0ms
2018-06-06 10:25:50,346-04 DEBUG
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetCapabilitiesVDSCommand]
(ForkJoinPool-1-worker-15) [2180968c] START, GetCapabilitiesVDSCommand(HostName
= lago-basic-suite-4-2-host-1, VdsIdAndVdsVDSCommandPar
ametersBase:{hostId='f44822d4-7967-44fb-b59e-23e73c7ba33c',
vds='Host[lago-basic-suite-4-2-host-1,f44822d4-7967-44fb-b59e-23e73c7ba33c]'}),
log id: 70ddbb6e
2018-06-06 10:25:50,487-04 INFO
[org.ovirt.engine.core.bll.network.host.LabelNicCommand] (default task-3)
[94ed8216-a9b8-4bb9-b5a3-90cb25196153] Running command: LabelNicCommand
internal: false. Entities affected : ID: f44822d4-7967-44f
b-b59e-23e73c7ba33c Type: VDSAction group CONFIGURE_HOST_NETWORK with role type
ADMIN
2018-06-06 10:25:50,496-04 INFO
[org.ovirt.engine.core.bll.network.host.HostSetupNetworksCommand] (default
task-3) [74f07638] Failed to Acquire Lock to object
'EngineLock:{exclusiveLocks='[HOST_NETWORKf44822d4-7967-44fb-b59e-23e73c7ba33c
=HOST_NETWORK]', sharedLocks=''}'
2018-06-06 10:25:50,531-04 DEBUG
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor] (default
task-3) [74f07638] method: get, params: [f44822d4-7967-44fb-b59e-23e73c7ba33c],
timeElapsed: 2ms
2018-06-06 10:25:50,535-04 DEBUG
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStatusVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-32) [] START,
SpmStatusVDSCommand(HostName = lago-basic-suite-4-2-host-1, SpmStatusVDSCommand
Parameters:{hostId='f44822d4-7967-44fb-b59e-23e73c7ba33c',
storagePoolId='cae56770-d7bd-4d03-9d74-d3b44ce1c20d'}), log id: 5ef2db2c
2018-06-06 10:25:50,571-04 DEBUG
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor]
(EE-ManagedThreadFactory-engineScheduled-Thread-32) [] method: runVdsCommand,
params: [SpmStatus, SpmStatusVDSCommandParameters:{hostId
='f44822d4-7967-44fb-b59e-23e73c7ba33c',
storagePoolId='cae56770-d7bd-4d03-9d74-d3b44ce1c20d'}], timeElapsed: 38ms
2018-06-06 10:25:51,454-04 DEBUG
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetCapabilitiesVDSCommand]
(ForkJoinPool-1-worker-15) [2180968c] FINISH, GetCapabilitiesVDSCommand,
return: Host[lago-basic-suite-4-2-host-1,f44822d4-7967-44fb-b5
9e-23e73c7ba33c], log id: 70ddbb6e
2018-06-06 10:25:51,454-04 DEBUG
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor]
(ForkJoinPool-1-worker-15) [2180968c] method: runVdsCommand, params:
[GetCapabilities, VdsIdAndVdsVDSCommandParametersBase:{hostId='f44
822d4-7967-44fb-b59e-23e73c7ba33c',
vds='Host[lago-basic-suite-4-2-host-1,f44822d4-7967-44fb-b59e-23e73c7ba33c]'}],
timeElapsed: 1112ms
2018-06-06 10:25:51,458-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetHardwareInfoAsyncVDSCommand]
(ForkJoinPool-1-worker-15) [2180968c] START,
GetHardwareInfoAsyncVDSCommand(HostName = lago-basic-suite-4-2-host-1,
VdsIdAndVdsVDS
CommandParametersBase:{hostId='f44822d4-7967-44fb-b59e-23e73c7ba33c',
vds='Host[lago-basic-suite-4-2-host-1,f44822d4-7967-44fb-b59e-23e73c7ba33c]'}),
log id: 18a9c9f5
2018-06-06 10:25:51,458-04 DEBUG
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor]
(ForkJoinPool-1-worker-15) [2180968c] method: runVdsCommand, params:
[GetHardwareInfoAsync, VdsIdAndVdsVDSCommandParametersBase:{hostId
='f44822d4-7967-44fb-b59e-23e73c7ba33c',
vds='Host[lago-basic-suite-4-2-host-1,f44822d4-7967-44fb-b59e-23e73c7ba33c]'}],
timeElapsed: 4ms
2018-06-06 10:25:51,521-04 DEBUG
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor]
(ForkJoinPool-1-worker-15) [21f11dbd] method: get, params:
[f44822d4-7967-44fb-b59e-23e73c7ba33c], timeElapsed: 3ms
2018-06-06 10:25:51,524-04 INFO
[org.ovirt.engine.core.bll.HandleVdsCpuFlagsOrClusterChangedCommand]
(ForkJoinPool-1-worker-15) [21f11dbd] Running command:
HandleVdsCpuFlagsOrClusterChangedCommand internal: true. Entities affected :
ID:
f44822d4-7967-44fb-b59e-23e73c7ba33c Type: VDS
2018-06-06 10:25:51,536-04 DEBUG
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor]
(ForkJoinPool-1-worker-15) [5a2c025e] method: get, params:
[f44822d4-7967-44fb-b59e-23e73c7ba33c], timeElapsed: 3ms
2018-06-06 10:25:51,539-04 INFO
[org.ovirt.engine.core.bll.HandleVdsVersionCommand] (ForkJoinPool-1-worker-15)
[5a2c025e] Running command: HandleVdsVersionCommand internal: true. Entities
affected : ID: f44822d4-7967-44fb-b59e-23e73c7ba
33c Type: VDS
2018-06-06 10:25:51,551-04 INFO
[org.ovirt.engine.core.bll.RefreshHostCapabilitiesCommand]
(ForkJoinPool-1-worker-15) [5a2c025e] Lock freed to object
'EngineLock:{exclusiveLocks='[HOST_NETWORKf44822d4-7967-44fb-b59e-23e73c7ba33c=HOST_NET
WORK, f44822d4-7967-44fb-b59e-23e73c7ba33c=VDS]', sharedLocks=''}'
ed: '
was (Author: dron):
This is a race inside engine when a command is sent for a locked object.
' here you can see that the lock was taken, another attempt to take the lock
was made and failed. then the lock was releas018-06-06 10:25:50,334-04 INFO
[org.ovirt.engine.core.bll.RefreshHostCapabilitiesCommand]
(ForkJoinPool-1-worker-15) [2180968c] Lock Acquired to object
'EngineLock:{exclusiveLocks='[HOST_NETWORKf44822d4-7967-44fb-b59e-23e73c7ba33c=HOST_
NETWORK, f44822d4-7967-44fb-b59e-23e73c7ba33c=VDS]', sharedLocks=''}'
2018-06-06 10:25:50,338-04 DEBUG
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor]
(ForkJoinPool-1-worker-15) [2180968c] method: get, params:
[f44822d4-7967-44fb-b59e-23e73c7ba33c], timeElapsed: 4ms
2018-06-06 10:25:50,341-04 INFO
[org.ovirt.engine.core.bll.RefreshHostCapabilitiesCommand]
(ForkJoinPool-1-worker-15) [2180968c] Running command:
RefreshHostCapabilitiesCommand internal: true. Entities affected : ID:
f44822d4-7967-44fb-
b59e-23e73c7ba33c Type: VDSAction group MANIPULATE_HOST with role type ADMIN
2018-06-06 10:25:50,341-04 DEBUG
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor]
(ForkJoinPool-1-worker-15) [2180968c] method: getVdsManager, params:
[f44822d4-7967-44fb-b59e-23e73c7ba33c], timeElapsed: 0ms
2018-06-06 10:25:50,346-04 DEBUG
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetCapabilitiesVDSCommand]
(ForkJoinPool-1-worker-15) [2180968c] START, GetCapabilitiesVDSCommand(HostName
= lago-basic-suite-4-2-host-1, VdsIdAndVdsVDSCommandPar
ametersBase:{hostId='f44822d4-7967-44fb-b59e-23e73c7ba33c',
vds='Host[lago-basic-suite-4-2-host-1,f44822d4-7967-44fb-b59e-23e73c7ba33c]'}),
log id: 70ddbb6e
2018-06-06 10:25:50,487-04 INFO
[org.ovirt.engine.core.bll.network.host.LabelNicCommand] (default task-3)
[94ed8216-a9b8-4bb9-b5a3-90cb25196153] Running command: LabelNicCommand
internal: false. Entities affected : ID: f44822d4-7967-44f
b-b59e-23e73c7ba33c Type: VDSAction group CONFIGURE_HOST_NETWORK with role type
ADMIN
2018-06-06 10:25:50,496-04 INFO
[org.ovirt.engine.core.bll.network.host.HostSetupNetworksCommand] (default
task-3) [74f07638] Failed to Acquire Lock to object
'EngineLock:{exclusiveLocks='[HOST_NETWORKf44822d4-7967-44fb-b59e-23e73c7ba33c
=HOST_NETWORK]', sharedLocks=''}'
2018-06-06 10:25:50,531-04 DEBUG
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor] (default
task-3) [74f07638] method: get, params: [f44822d4-7967-44fb-b59e-23e73c7ba33c],
timeElapsed: 2ms
2018-06-06 10:25:50,535-04 DEBUG
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStatusVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-32) [] START,
SpmStatusVDSCommand(HostName = lago-basic-suite-4-2-host-1, SpmStatusVDSCommand
Parameters:{hostId='f44822d4-7967-44fb-b59e-23e73c7ba33c',
storagePoolId='cae56770-d7bd-4d03-9d74-d3b44ce1c20d'}), log id: 5ef2db2c
2018-06-06 10:25:50,571-04 DEBUG
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor]
(EE-ManagedThreadFactory-engineScheduled-Thread-32) [] method: runVdsCommand,
params: [SpmStatus, SpmStatusVDSCommandParameters:{hostId
='f44822d4-7967-44fb-b59e-23e73c7ba33c',
storagePoolId='cae56770-d7bd-4d03-9d74-d3b44ce1c20d'}], timeElapsed: 38ms
2018-06-06 10:25:51,454-04 DEBUG
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetCapabilitiesVDSCommand]
(ForkJoinPool-1-worker-15) [2180968c] FINISH, GetCapabilitiesVDSCommand,
return: Host[lago-basic-suite-4-2-host-1,f44822d4-7967-44fb-b5
9e-23e73c7ba33c], log id: 70ddbb6e
2018-06-06 10:25:51,454-04 DEBUG
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor]
(ForkJoinPool-1-worker-15) [2180968c] method: runVdsCommand, params:
[GetCapabilities, VdsIdAndVdsVDSCommandParametersBase:{hostId='f44
822d4-7967-44fb-b59e-23e73c7ba33c',
vds='Host[lago-basic-suite-4-2-host-1,f44822d4-7967-44fb-b59e-23e73c7ba33c]'}],
timeElapsed: 1112ms
2018-06-06 10:25:51,458-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetHardwareInfoAsyncVDSCommand]
(ForkJoinPool-1-worker-15) [2180968c] START,
GetHardwareInfoAsyncVDSCommand(HostName = lago-basic-suite-4-2-host-1,
VdsIdAndVdsVDS
CommandParametersBase:{hostId='f44822d4-7967-44fb-b59e-23e73c7ba33c',
vds='Host[lago-basic-suite-4-2-host-1,f44822d4-7967-44fb-b59e-23e73c7ba33c]'}),
log id: 18a9c9f5
2018-06-06 10:25:51,458-04 DEBUG
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor]
(ForkJoinPool-1-worker-15) [2180968c] method: runVdsCommand, params:
[GetHardwareInfoAsync, VdsIdAndVdsVDSCommandParametersBase:{hostId
='f44822d4-7967-44fb-b59e-23e73c7ba33c',
vds='Host[lago-basic-suite-4-2-host-1,f44822d4-7967-44fb-b59e-23e73c7ba33c]'}],
timeElapsed: 4ms
2018-06-06 10:25:51,521-04 DEBUG
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor]
(ForkJoinPool-1-worker-15) [21f11dbd] method: get, params:
[f44822d4-7967-44fb-b59e-23e73c7ba33c], timeElapsed: 3ms
2018-06-06 10:25:51,524-04 INFO
[org.ovirt.engine.core.bll.HandleVdsCpuFlagsOrClusterChangedCommand]
(ForkJoinPool-1-worker-15) [21f11dbd] Running command:
HandleVdsCpuFlagsOrClusterChangedCommand internal: true. Entities affected :
ID:
f44822d4-7967-44fb-b59e-23e73c7ba33c Type: VDS
2018-06-06 10:25:51,536-04 DEBUG
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor]
(ForkJoinPool-1-worker-15) [5a2c025e] method: get, params:
[f44822d4-7967-44fb-b59e-23e73c7ba33c], timeElapsed: 3ms
2018-06-06 10:25:51,539-04 INFO
[org.ovirt.engine.core.bll.HandleVdsVersionCommand] (ForkJoinPool-1-worker-15)
[5a2c025e] Running command: HandleVdsVersionCommand internal: true. Entities
affected : ID: f44822d4-7967-44fb-b59e-23e73c7ba
33c Type: VDS
2018-06-06 10:25:51,551-04 INFO
[org.ovirt.engine.core.bll.RefreshHostCapabilitiesCommand]
(ForkJoinPool-1-worker-15) [5a2c025e] Lock freed to object
'EngineLock:{exclusiveLocks='[HOST_NETWORKf44822d4-7967-44fb-b59e-23e73c7ba33c=HOST_NET
WORK, f44822d4-7967-44fb-b59e-23e73c7ba33c=VDS]', sharedLocks=''}'
ed: '
> 005_network_by_label.assign_hosts_network_label
> ------------------------------------------------
>
> Key: OVIRT-2148
> URL: https://ovirt-jira.atlassian.net/browse/OVIRT-2148
> Project: oVirt - virtualization made easy
> Issue Type: Task
> Reporter: Dafna Ron
> Assignee: infra
> Labels: ost_failures, ost_race
>
> Change 91614,10 (ovirt-provider-ovn) is probably the reason behind recent
> system test failures in the "ovirt-4.2" change queue and needs to be fixed.
> This change had been removed from the testing queue. Artifacts build from this
> change will not be released until it is fixed.
> For further details about the change see:
> https://gerrit.ovirt.org/#/c/91614/10
> For failed test results see:
> http://jenkins.ovirt.org/job/ovirt-4.2_change-queue-tester/2312/
> Fault reason is "Operation Failed". Fault detail is "[Cannot add Label.
> Another Setup Networks or Host Refresh process in progress on the host.
> Please try later.]". HTTP response code is 409.
--
This message was sent by Atlassian Jira
(v1001.0.0-SNAPSHOT#100087)
_______________________________________________
Infra mailing list -- [email protected]
To unsubscribe send an email to [email protected]
Privacy Statement: https://www.ovirt.org/site/privacy-policy/
oVirt Code of Conduct:
https://www.ovirt.org/community/about/community-guidelines/
List Archives:
https://lists.ovirt.org/archives/list/[email protected]/message/X22NJQK7XBY64PBDZTFUAHTMNZUV3KS2/
