[JIRA] (OVIRT-2148) 005_network_by_label.assign_hosts_network_label

[ 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)
participants (1)
-
Dafna Ron (oVirt JIRA)