Created attachment 817473 [details] engine.log Description of problem: When I export a disk to glance storage domain, the export button does not get greyed-out for the first few seconds, so user is able to export the disk twice. Version-Release number of selected component (if applicable): rhevm-3.3.0-0.28.beta1.el6ev.noarch How reproducible: 100% Steps to Reproduce: 1. add glance as an external provider to RHEVM 2. create a new disk in RHEV 3. export the disk to glance storage domain and immediately, export it again Actual results: We are able to export the disk again. After that, 2 situations can occur: 1) we're getting a CanDoAction failure in engine: 2013-10-30 16:02:23,912 WARN [org.ovirt.engine.core.bll.ExportRepoImageCommand] (ajp-/127.0.0.1:8702-9) [7f489f0e] CanDoAction of action ExportRepoImage failed. Reasons:VAR__ACTION__EXPORT,VAR__TYPE__VM_DISK,ACTI ON_TYPE_FAILED_DISK_IS_BEING_EXPORTED,$DiskAlias iscsi1-4_Disk2 2) disk export start normally twice Expected results: User should not be able to export the disk twice to glance storage domain. Additional info: logs
(In reply to Elad from comment #0) > Actual results: > We are able to export the disk again. After that, 2 situations can occur: > 1) we're getting a CanDoAction failure in engine: There is no way to get rid of the race in the GUI button (and no reason to try to). All the locking mechanisms are maintained in the backend as it's the entity that coordinates the operations. Getting the canDoAction error is the correct result here. > 2013-10-30 16:02:23,912 WARN > [org.ovirt.engine.core.bll.ExportRepoImageCommand] (ajp-/127.0.0.1:8702-9) > [7f489f0e] CanDoAction of action ExportRepoImage failed. > Reasons:VAR__ACTION__EXPORT,VAR__TYPE__VM_DISK,ACTI > ON_TYPE_FAILED_DISK_IS_BEING_EXPORTED,$DiskAlias iscsi1-4_Disk2 > > 2) disk export start normally twice There's no indication of this second case in the attached logs. ExportRepoImageCommand 1c4b3a5c seems unrelated to this bz (1 single successful execution): 2013-10-30 14:53:59,278 [1c4b3a5c] Lock Acquired to object EngineLock [exclusiveLocks= key: c626160c-a2e5-4173-9d15-883ed8389428 value: DISK 2013-10-30 14:53:59,374 [1c4b3a5c] Running command: ExportRepoImageCommand internal: false. Entities affected : ID: c626160c-a2e5-4173-9d15-883ed8389428 Type: Disk, ID: 344dd3e1-9ccd-4f94-9b9e-5a36ad86dee2 Type: Storage 2013-10-30 14:54:00,055 [1c4b3a5c] Lock freed to object EngineLock [exclusiveLocks= key: c626160c-a2e5-4173-9d15-883ed8389428 value: DISK 2013-10-30 14:54:11,182 Ending command successfully: org.ovirt.engine.core.bll.ExportRepoImageCommand ExportRepoImageCommand 677d9e65 is successfully executed and 7f489f0e fails on ACTION_TYPE_FAILED_DISK_IS_BEING_EXPORTED: 2013-10-30 16:02:18,949 [677d9e65] Lock Acquired to object EngineLock [exclusiveLocks= key: b3e171d3-7956-498f-a65a-62a948489685 value: DISK 2013-10-30 16:02:19,020 [677d9e65] Running command: ExportRepoImageCommand internal: false. Entities affected : ID: b3e171d3-7956-498f-a65a-62a948489685 Type: Disk, ID: 344dd3e1-9ccd-4f94-9b9e-5a36ad86dee2 Type: Storage 2013-10-30 16:02:23,912 [7f489f0e] Failed to Acquire Lock to object EngineLock [exclusiveLocks= key: b3e171d3-7956-498f-a65a-62a948489685 value: DISK 2013-10-30 16:02:23,912 WARN [org.ovirt.engine.core.bll.ExportRepoImageCommand] (ajp-/127.0.0.1:8702-9) [7f489f0e] CanDoAction of action ExportRepoImage failed. Reasons:VAR__ACTION__EXPORT,VAR__TYPE__VM_DISK,ACTION_TYPE_FAILED_DISK_IS_BEING_EXPORTED,$DiskAlias iscsi1-4_Disk2 2013-10-30 16:02:31,451 [677d9e65] Lock freed to object EngineLock [exclusiveLocks= key: b3e171d3-7956-498f-a65a-62a948489685 value: DISK 2013-10-30 16:03:31,533 Ending command successfully: org.ovirt.engine.core.bll.ExportRepoImageCommand ExportRepoImageCommand 5a532dc7 fails because the vm is running (ACTION_TYPE_FAILED_VM_IS_RUNNING) and 327e42cc is successful: 2013-10-30 16:09:23,958 [5a532dc7] Lock Acquired to object EngineLock [exclusiveLocks= key: aec61aed-16d4-4c0b-b180-9a5248e867cc value: DISK 2013-10-30 16:09:24,004 WARN [org.ovirt.engine.core.bll.ExportRepoImageCommand] (ajp-/127.0.0.1:8702-4) [5a532dc7] CanDoAction of action ExportRepoImage failed. Reasons:VAR__ACTION__EXPORT,VAR__TYPE__VM_DISK,ACTION_TYPE_FAILED_VM_IS_RUNNING 2013-10-30 16:09:24,004 [5a532dc7] Lock freed to object EngineLock [exclusiveLocks= key: aec61aed-16d4-4c0b-b180-9a5248e867cc value: DISK 2013-10-30 16:09:43,306 [327e42cc] Lock Acquired to object EngineLock [exclusiveLocks= key: aec61aed-16d4-4c0b-b180-9a5248e867cc value: DISK 2013-10-30 16:09:43,385 [327e42cc] Running command: ExportRepoImageCommand internal: false. Entities affected : ID: aec61aed-16d4-4c0b-b180-9a5248e867cc Type: Disk, ID: 344dd3e1-9ccd-4f94-9b9e-5a36ad86dee2 Type: Storage 2013-10-30 16:09:44,104 [327e42cc] Lock freed to object EngineLock [exclusiveLocks= key: aec61aed-16d4-4c0b-b180-9a5248e867cc value: DISK 2013-10-30 16:12:01,819 Ending command successfully: org.ovirt.engine.core.bll.ExportRepoImageCommand Can you provide a log where the second case is present? Thanks.
(In reply to Federico Simoncelli from comment #2) > (In reply to Elad from comment #0) > > Actual results: > > We are able to export the disk again. After that, 2 situations can occur: > > 1) we're getting a CanDoAction failure in engine: > > There is no way to get rid of the race in the GUI button (and no reason to > try to). All the locking mechanisms are maintained in the backend as it's > the entity that coordinates the operations. > Getting the canDoAction error is the correct result here. The 'export' button is not greyed out for a relatively long time, much more than other buttons that becomes greyed out like move or copy. > > > 2013-10-30 16:02:23,912 WARN > > [org.ovirt.engine.core.bll.ExportRepoImageCommand] (ajp-/127.0.0.1:8702-9) > > [7f489f0e] CanDoAction of action ExportRepoImage failed. > > Reasons:VAR__ACTION__EXPORT,VAR__TYPE__VM_DISK,ACTI > > ON_TYPE_FAILED_DISK_IS_BEING_EXPORTED,$DiskAlias iscsi1-4_Disk2 > > > > 2) disk export start normally twice > > There's no indication of this second case in the attached logs. > > > ExportRepoImageCommand 1c4b3a5c seems unrelated to this bz (1 single > successful execution): > > 2013-10-30 14:53:59,278 [1c4b3a5c] Lock Acquired to object EngineLock > [exclusiveLocks= key: c626160c-a2e5-4173-9d15-883ed8389428 value: DISK > 2013-10-30 14:53:59,374 [1c4b3a5c] Running command: ExportRepoImageCommand > internal: false. Entities affected : ID: > c626160c-a2e5-4173-9d15-883ed8389428 Type: Disk, ID: > 344dd3e1-9ccd-4f94-9b9e-5a36ad86dee2 Type: Storage > 2013-10-30 14:54:00,055 [1c4b3a5c] Lock freed to object EngineLock > [exclusiveLocks= key: c626160c-a2e5-4173-9d15-883ed8389428 value: DISK > 2013-10-30 14:54:11,182 Ending command successfully: > org.ovirt.engine.core.bll.ExportRepoImageCommand > > > ExportRepoImageCommand 677d9e65 is successfully executed and 7f489f0e fails > on ACTION_TYPE_FAILED_DISK_IS_BEING_EXPORTED: > > 2013-10-30 16:02:18,949 [677d9e65] Lock Acquired to object EngineLock > [exclusiveLocks= key: b3e171d3-7956-498f-a65a-62a948489685 value: DISK > 2013-10-30 16:02:19,020 [677d9e65] Running command: ExportRepoImageCommand > internal: false. Entities affected : ID: > b3e171d3-7956-498f-a65a-62a948489685 Type: Disk, ID: > 344dd3e1-9ccd-4f94-9b9e-5a36ad86dee2 Type: Storage > 2013-10-30 16:02:23,912 [7f489f0e] Failed to Acquire Lock to object > EngineLock [exclusiveLocks= key: b3e171d3-7956-498f-a65a-62a948489685 value: > DISK > 2013-10-30 16:02:23,912 WARN > [org.ovirt.engine.core.bll.ExportRepoImageCommand] (ajp-/127.0.0.1:8702-9) > [7f489f0e] CanDoAction of action ExportRepoImage failed. > Reasons:VAR__ACTION__EXPORT,VAR__TYPE__VM_DISK, > ACTION_TYPE_FAILED_DISK_IS_BEING_EXPORTED,$DiskAlias iscsi1-4_Disk2 > 2013-10-30 16:02:31,451 [677d9e65] Lock freed to object EngineLock > [exclusiveLocks= key: b3e171d3-7956-498f-a65a-62a948489685 value: DISK > 2013-10-30 16:03:31,533 Ending command successfully: > org.ovirt.engine.core.bll.ExportRepoImageCommand > > > ExportRepoImageCommand 5a532dc7 fails because the vm is running > (ACTION_TYPE_FAILED_VM_IS_RUNNING) and 327e42cc is successful: > > 2013-10-30 16:09:23,958 [5a532dc7] Lock Acquired to object EngineLock > [exclusiveLocks= key: aec61aed-16d4-4c0b-b180-9a5248e867cc value: DISK > 2013-10-30 16:09:24,004 WARN > [org.ovirt.engine.core.bll.ExportRepoImageCommand] (ajp-/127.0.0.1:8702-4) > [5a532dc7] CanDoAction of action ExportRepoImage failed. > Reasons:VAR__ACTION__EXPORT,VAR__TYPE__VM_DISK, > ACTION_TYPE_FAILED_VM_IS_RUNNING > 2013-10-30 16:09:24,004 [5a532dc7] Lock freed to object EngineLock > [exclusiveLocks= key: aec61aed-16d4-4c0b-b180-9a5248e867cc value: DISK > 2013-10-30 16:09:43,306 [327e42cc] Lock Acquired to object EngineLock > [exclusiveLocks= key: aec61aed-16d4-4c0b-b180-9a5248e867cc value: DISK > 2013-10-30 16:09:43,385 [327e42cc] Running command: ExportRepoImageCommand > internal: false. Entities affected : ID: > aec61aed-16d4-4c0b-b180-9a5248e867cc Type: Disk, ID: > 344dd3e1-9ccd-4f94-9b9e-5a36ad86dee2 Type: Storage > 2013-10-30 16:09:44,104 [327e42cc] Lock freed to object EngineLock > [exclusiveLocks= key: aec61aed-16d4-4c0b-b180-9a5248e867cc value: DISK > 2013-10-30 16:12:01,819 Ending command successfully: > org.ovirt.engine.core.bll.ExportRepoImageCommand > > > Can you provide a log where the second case is present? Thanks. attaching the relevant log file
Created attachment 818045 [details] engine.log(2) First export to image 38644e32-c2e2-4dd7-8db4-16144f5702e9 2013-10-31 21:46:16,353 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadImageVDSCommand] (pool-4-thread-45) [6236395b] -- uploadImage parameters: srcSpUUID=023b67f5-f02e-4390-9dce-3cb4305f9e98 srcSdUUID=c51aba4c-8a0e-4eb0-a6f3-d2623f7330be srcImageGUID=38644e32-c2e2-4dd7-8db4-16144f5702e9 srcVolUUID=a691fd35-a122-474a-aa40-4c9f22b7850b Second export to image 38644e32-c2e2-4dd7-8db4-16144f5702e9 2013-10-31 21:46:20,258 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadImageVDSCommand] (pool-4-thread-45) [6f2dcce9] -- uploadImage parameters: srcSpUUID=023b67f5-f02e-4390-9dce-3cb4305f9e98 srcSdUUID=c51aba4c-8a0e-4eb0-a6f3-d2623f7330be srcImageGUID=38644e32-c2e2-4dd7-8db4-16144f5702e9 srcVolUUID=a691fd35-a122-474a-aa40-4c9f22b7850b
(In reply to Elad from comment #3) > (In reply to Federico Simoncelli from comment #2) > > (In reply to Elad from comment #0) > > > Actual results: > > > We are able to export the disk again. After that, 2 situations can occur: > > > 1) we're getting a CanDoAction failure in engine: > > > > There is no way to get rid of the race in the GUI button (and no reason to > > try to). All the locking mechanisms are maintained in the backend as it's > > the entity that coordinates the operations. > > Getting the canDoAction error is the correct result here. > > The 'export' button is not greyed out for a relatively long time, much more > than other buttons that becomes greyed out like move or copy. I just tested that and it takes about 5 seconds both for "Move" and "Export" (in the storage tab) to grey the button. Adding some debugging showed that the time passed since receiving the command and the image being locked is sub-second: 1383574767356 Running action: MoveDisks 1383574767389 Running multiple actions: MoveOrCopyDisk 1383574767476 Running action: MoveImageGroup 1383574767622 Locking image for move: 69859a29-5eee-45bd-8522-03fd111cede1 = 266 milliseconds from receiving the command to locking the image 1383574807739 Running multiple actions: ExportRepoImage 1383574807863 Locking image for export: 1a0e0ac1-e07a-40db-946d-376d104ed2e7 = 124 milliseconds from receiving the command to locking the image The image status is updated in the UI at constant time so there's nothing else to do here (or anything different between Move/Copy/Export).
(In reply to Elad from comment #4) > Created attachment 818045 [details] > engine.log(2) > > First export to image 38644e32-c2e2-4dd7-8db4-16144f5702e9 > > 2013-10-31 21:46:16,353 INFO > [org.ovirt.engine.core.vdsbroker.irsbroker.UploadImageVDSCommand] > (pool-4-thread-45) [6236395b] -- uploadImage parameters: > srcSpUUID=023b67f5-f02e-4390-9dce-3cb4305f9e98 > srcSdUUID=c51aba4c-8a0e-4eb0-a6f3-d2623f7330be > srcImageGUID=38644e32-c2e2-4dd7-8db4-16144f5702e9 > srcVolUUID=a691fd35-a122-474a-aa40-4c9f22b7850b > > Second export to image 38644e32-c2e2-4dd7-8db4-16144f5702e9 > > 2013-10-31 21:46:20,258 INFO > [org.ovirt.engine.core.vdsbroker.irsbroker.UploadImageVDSCommand] > (pool-4-thread-45) [6f2dcce9] -- uploadImage parameters: > srcSpUUID=023b67f5-f02e-4390-9dce-3cb4305f9e98 > srcSdUUID=c51aba4c-8a0e-4eb0-a6f3-d2623f7330be > srcImageGUID=38644e32-c2e2-4dd7-8db4-16144f5702e9 > srcVolUUID=a691fd35-a122-474a-aa40-4c9f22b7850b Thanks! This issue is addressed in the gerrit patch I'm adding to the external tracker.
Disk export to glance domain is blocked to user when the disk is being exported. User gets: "Error while executing action: Cannot export Virtual Machine Disk. Disk iscs4-1_Disk1 is being exported." Verified on is23 rhevm-3.3.0-0.33.beta1.el6ev.noarch
Closing - RHEV 3.3 Released