Bug 1523253
| Summary: | When canceling a download, the engine finalizes the operation as if it was completed successfully | ||
|---|---|---|---|
| Product: | [oVirt] ovirt-engine | Reporter: | Idan Shaby <ishaby> |
| Component: | BLL.Storage | Assignee: | Idan Shaby <ishaby> |
| Status: | CLOSED CURRENTRELEASE | QA Contact: | Avihai <aefrat> |
| Severity: | unspecified | Docs Contact: | |
| Priority: | unspecified | ||
| Version: | 4.2.0 | CC: | amureini, bugs, ishaby |
| Target Milestone: | ovirt-4.2.0 | Flags: | rule-engine:
ovirt-4.2+
|
| Target Release: | --- | ||
| Hardware: | Unspecified | ||
| OS: | Unspecified | ||
| Whiteboard: | |||
| Fixed In Version: | ovirt-engine-4.2.0.1 | Doc Type: | If docs needed, set a value |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2017-12-20 11:36:37 UTC | Type: | Bug |
| Regression: | --- | Mount Type: | --- |
| Documentation: | --- | CRM: | |
| Verified Versions: | Category: | --- | |
| oVirt Team: | Storage | RHEL 7.3 requirements from Atomic Host: | |
| Cloudforms Team: | --- | Target Upstream Version: | |
| Embargoed: | |||
This bug is targeted 4.2.1 but is modified in 4.2.0. Can you please check / verify this bug status and set target milestone and bug status accordingly? This fix was included in the ovirt-engine-4.2.0.1 tag verified on 4.2.0.2-0.1. This bugzilla is included in oVirt 4.2.0 release, published on Dec 20th 2017. Since the problem described in this bug report should be resolved in oVirt 4.2.0 release, published on Dec 20th 2017, it has been closed with a resolution of CURRENT RELEASE. If the solution does not work for you, please open a new bug report. |
Description of problem: When canceling a download, the engine finalizes the operation as if it was completed successfully. Instead of moving to phase "Finalizing Success" it should move to phase "Cancelled". Version-Release number of selected component (if applicable): 88e9120392ff0630467afd1849d85df382edeb2a How reproducible: 100% Steps to Reproduce: 1. Start an image download using the API. 2. Cancel the download from the webadmin. Actual results: From the engine's log: 2017-12-07 11:19:04,281+02 INFO [org.ovirt.engine.core.bll.storage.disk.image.ImageTransferUpdater] (default task-105) [3466cd2b-d5fa-4025-9818-c1d05816b9b2] Updating image transfer 97f29f8c-bdcf-49e3-b579-6652758bdb14 (image 7d7b4bee-c0d7-4afb-a3d2-b5a4b512eb5f) phase to Finalizing Success 2017-12-07 11:19:10,105+02 INFO [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-16) [725a0c1f-0636-4ed2-adb9-9416812187c7] Finalizing successful transfer for Download disk 'disk1' (id '00000000-0000-0000-0000-000000000000') 2017-12-07 11:19:10,107+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.RemoveImageTicketVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-16) [725a0c1f-0636-4ed2-adb9-9416812187c7] START, RemoveImageTicketVDSCommand(HostName = vdsm, RemoveImageTicketVDSCommandParameters:{hostId='82e86d49-bf94-4c41-bed6-02b8044f13e2', ticketId='ba39ee71-6189-4c2a-899a-91445ef649dc', timeout='null'}), log id: 79113e91 2017-12-07 11:19:10,111+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.RemoveImageTicketVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-16) [725a0c1f-0636-4ed2-adb9-9416812187c7] FINISH, RemoveImageTicketVDSCommand, return: StatusOnlyReturn [status=Status [code=0, message=Done]], log id: 79113e91 2017-12-07 11:19:10,111+02 INFO [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-16) [725a0c1f-0636-4ed2-adb9-9416812187c7] Successfully stopped image transfer session for ticket 'ba39ee71-6189-4c2a-899a-91445ef649dc' 2017-12-07 11:19:10,131+02 INFO [org.ovirt.engine.core.bll.storage.disk.image.ImageTransferUpdater] (EE-ManagedThreadFactory-engineScheduled-Thread-16) [725a0c1f-0636-4ed2-adb9-9416812187c7] Updating image transfer 97f29f8c-bdcf-49e3-b579-6652758bdb14 (image 7d7b4bee-c0d7-4afb-a3d2-b5a4b512eb5f) phase to Finished Success 2017-12-07 11:19:10,145+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.TeardownImageVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-16) [725a0c1f-0636-4ed2-adb9-9416812187c7] START, TeardownImageVDSCommand(HostName = vdsm, ImageActionsVDSCommandParameters:{hostId='82e86d49-bf94-4c41-bed6-02b8044f13e2'}), log id: 64681f35 2017-12-07 11:19:11,675+02 INFO [org.ovirt.engine.core.sso.utils.AuthenticationUtils] (default task-107) [] User admin@internal successfully logged in with scopes: ovirt-app-api ovirt-ext=token-info:authz-search ovirt-ext=token-info:public-authz-search ovirt-ext=token-info:validate ovirt-ext=token:password-access 2017-12-07 11:19:11,688+02 INFO [org.ovirt.engine.core.bll.aaa.CreateUserSessionCommand] (default task-106) [3fa1ae14] Running command: CreateUserSessionCommand internal: false. 2017-12-07 11:19:11,706+02 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-106) [3fa1ae14] EVENT_ID: USER_VDC_LOGIN(30), User admin@internal-authz connecting from '10.35.1.94' using session 'rzTE35TzpJL5rzXoUkyET9C1nS77PePR7ary/u4fPdDYWn8JlM03V99AhvyoiEOSSlgrLvAD4d/xCJrZrnUXNg==' logged in. 2017-12-07 11:19:11,715+02 INFO [org.ovirt.engine.core.bll.aaa.LogoutSessionCommand] (default task-106) [cb37206] Running command: LogoutSessionCommand internal: false. 2017-12-07 11:19:11,723+02 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-106) [cb37206] EVENT_ID: USER_VDC_LOGOUT(31), User admin@internal-authz connected from '10.35.1.94' using session 'rzTE35TzpJL5rzXoUkyET9C1nS77PePR7ary/u4fPdDYWn8JlM03V99AhvyoiEOSSlgrLvAD4d/xCJrZrnUXNg==' logged out. 2017-12-07 11:19:12,866+02 INFO [org.ovirt.engine.core.sso.servlets.OAuthRevokeServlet] (default task-109) [] User admin@internal successfully logged out 2017-12-07 11:19:12,879+02 INFO [org.ovirt.engine.core.bll.aaa.TerminateSessionsForTokenCommand] (default task-112) [9872c73] Running command: TerminateSessionsForTokenCommand internal: true. 2017-12-07 11:19:20,023+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-16) [725a0c1f-0636-4ed2-adb9-9416812187c7] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), VDSM vdsm command TeardownImageVDS failed: Cannot deactivate Logical Volume: ('General Storage Exception: ("5 [] [\' Logical volume d757fbb7-d001-49d0-b6c2-9b313b32c12a/ce646815-03b4-4231-9911-31a180955717 in use.\']\\nd757fbb7-d001-49d0-b6c2-9b313b32c12a/[\'ce646815-03b4-4231-9911-31a180955717\']",)',) 2017-12-07 11:19:20,024+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.TeardownImageVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-16) [725a0c1f-0636-4ed2-adb9-9416812187c7] Command 'TeardownImageVDSCommand(HostName = vdsm, ImageActionsVDSCommandParameters:{hostId='82e86d49-bf94-4c41-bed6-02b8044f13e2'})' execution failed: VDSGenericException: VDSErrorException: Failed in vdscommand to TeardownImageVDS, error = Cannot deactivate Logical Volume: ('General Storage Exception: ("5 [] [\' Logical volume d757fbb7-d001-49d0-b6c2-9b313b32c12a/ce646815-03b4-4231-9911-31a180955717 in use.\']\\nd757fbb7-d001-49d0-b6c2-9b313b32c12a/[\'ce646815-03b4-4231-9911-31a180955717\']",)',) 2017-12-07 11:19:20,024+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.TeardownImageVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-16) [725a0c1f-0636-4ed2-adb9-9416812187c7] FINISH, TeardownImageVDSCommand, log id: 64681f35 2017-12-07 11:19:20,024+02 ERROR [org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller] (EE-ManagedThreadFactory-engineScheduled-Thread-16) [725a0c1f-0636-4ed2-adb9-9416812187c7] Error invoking callback method 'doPolling' for 'ACTIVE' command '97f29f8c-bdcf-49e3-b579-6652758bdb14' 2017-12-07 11:19:20,024+02 ERROR [org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller] (EE-ManagedThreadFactory-engineScheduled-Thread-16) [725a0c1f-0636-4ed2-adb9-9416812187c7] Exception: org.ovirt.engine.core.common.errors.EngineException: EngineException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed in vdscommand to TeardownImageVDS, error = Cannot deactivate Logical Volume: ('General Storage Exception: ("5 [] [\' Logical volume d757fbb7-d001-49d0-b6c2-9b313b32c12a/ce646815-03b4-4231-9911-31a180955717 in use.\']\\nd757fbb7-d001-49d0-b6c2-9b313b32c12a/[\'ce646815-03b4-4231-9911-31a180955717\']",)',) (Failed with error CannotDeactivateLogicalVolume and code 552) at org.ovirt.engine.core.bll.VdsHandler.handleVdsResult(VdsHandler.java:118) [bll.jar:] at org.ovirt.engine.core.bll.VDSBrokerFrontendImpl.runVdsCommand(VDSBrokerFrontendImpl.java:33) [bll.jar:] at org.ovirt.engine.core.bll.CommandBase.runVdsCommand(CommandBase.java:2098) [bll.jar:] at org.ovirt.engine.core.bll.storage.StorageHandlingCommandBase.runVdsCommand(StorageHandlingCommandBase.java:759) [bll.jar:] at org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand.tearDownImage(TransferDiskImageCommand.java:130) [bll.jar:] at org.ovirt.engine.core.bll.storage.disk.image.TransferImageCommand.handleFinalizingSuccess(TransferImageCommand.java:423) [bll.jar:] at org.ovirt.engine.core.bll.storage.disk.image.TransferImageCommand.executeStateHandler(TransferImageCommand.java:178) [bll.jar:] at org.ovirt.engine.core.bll.storage.disk.image.TransferImageCommand.proceedCommandExecution(TransferImageCommand.java:147) [bll.jar:] at org.ovirt.engine.core.bll.storage.disk.image.TransferImageCommandCallback.doPolling(TransferImageCommandCallback.java:21) [bll.jar:] at org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller.invokeCallbackMethodsImpl(CommandCallbacksPoller.java:145) [bll.jar:] at org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller.invokeCallbackMethods(CommandCallbacksPoller.java:106) [bll.jar:] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [rt.jar:1.8.0_151] at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [rt.jar:1.8.0_151] at org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.access$201(ManagedScheduledThreadPoolExecutor.java:383) [javax.enterprise.concurrent-1.0.jar:] at org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.run(ManagedScheduledThreadPoolExecutor.java:534) [javax.enterprise.concurrent-1.0.jar:] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [rt.jar:1.8.0_151] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [rt.jar:1.8.0_151] at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_151] at org.glassfish.enterprise.concurrent.ManagedThreadFactoryImpl$ManagedThread.run(ManagedThreadFactoryImpl.java:250) [javax.enterprise.concurrent-1.0.jar:] at org.jboss.as.ee.concurrent.service.ElytronManagedThreadFactory$ElytronManagedThread.run(ElytronManagedThreadFactory.java:78) Caused by: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed in vdscommand to TeardownImageVDS, error = Cannot deactivate Logical Volume: ('General Storage Exception: ("5 [] [\' Logical volume d757fbb7-d001-49d0-b6c2-9b313b32c12a/ce646815-03b4-4231-9911-31a180955717 in use.\']\\nd757fbb7-d001-49d0-b6c2-9b313b32c12a/[\'ce646815-03b4-4231-9911-31a180955717\']",)',) at org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.proceedProxyReturnValue(BrokerCommandBase.java:183) [vdsbroker.jar:] at org.ovirt.engine.core.vdsbroker.vdsbroker.ImageActionsVDSCommandBase.executeVdsBrokerCommand(ImageActionsVDSCommandBase.java:20) [vdsbroker.jar:] at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:112) [vdsbroker.jar:] at org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:73) [vdsbroker.jar:] at org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:33) [dal.jar:] at org.ovirt.engine.core.vdsbroker.vdsbroker.DefaultVdsCommandExecutor.execute(DefaultVdsCommandExecutor.java:14) [vdsbroker.jar:] at org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceManager.java:387) [vdsbroker.jar:] at org.ovirt.engine.core.vdsbroker.ResourceManager$Proxy$_$$_WeldSubclass.runVdsCommand$$super(Unknown Source) [vdsbroker.jar:] at sun.reflect.GeneratedMethodAccessor75.invoke(Unknown Source) [:1.8.0_151] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_151] at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_151] at org.jboss.weld.interceptor.proxy.TerminalAroundInvokeInvocationContext.proceedInternal(TerminalAroundInvokeInvocationContext.java:49) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final] at org.jboss.weld.interceptor.proxy.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:77) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final] at org.ovirt.engine.core.common.di.interceptor.LoggingInterceptor.apply(LoggingInterceptor.java:12) [common.jar:] at sun.reflect.GeneratedMethodAccessor70.invoke(Unknown Source) [:1.8.0_151] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_151] at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_151] at org.jboss.weld.interceptor.reader.SimpleInterceptorInvocation$SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:73) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final] at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeAroundInvoke(InterceptorMethodHandler.java:84) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final] at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeInterception(InterceptorMethodHandler.java:72) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final] at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.invoke(InterceptorMethodHandler.java:56) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final] at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:79) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final] at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:68) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final] at org.ovirt.engine.core.vdsbroker.ResourceManager$Proxy$_$$_WeldSubclass.runVdsCommand(Unknown Source) [vdsbroker.jar:] ... 19 more 2017-12-07 11:19:21,037+02 INFO [org.ovirt.engine.core.bll.storage.disk.image.ImageTransferUpdater] (EE-ManagedThreadFactory-engineScheduled-Thread-83) [725a0c1f-0636-4ed2-adb9-9416812187c7] Updating image transfer 97f29f8c-bdcf-49e3-b579-6652758bdb14 (image 7d7b4bee-c0d7-4afb-a3d2-b5a4b512eb5f) phase to Finished Failure 2017-12-07 11:19:21,049+02 ERROR [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-83) [725a0c1f-0636-4ed2-adb9-9416812187c7] Failed to transfer disk '00000000-0000-0000-0000-000000000000' (command id '97f29f8c-bdcf-49e3-b579-6652758bdb14') 2017-12-07 11:19:21,051+02 INFO [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-83) [725a0c1f-0636-4ed2-adb9-9416812187c7] Ending command 'org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand' successfully. Expected results: The engine should move to phase "Cancelled", just like the upload flow.