Bug 1534227
| Summary: | Confusing logging when cold-moving a disk - the term CreateSnapshot is referenced | ||||||
|---|---|---|---|---|---|---|---|
| Product: | [oVirt] ovirt-engine | Reporter: | Elad <ebenahar> | ||||
| Component: | BLL.Storage | Assignee: | Allon Mureinik <amureini> | ||||
| Status: | CLOSED CURRENTRELEASE | QA Contact: | Elad <ebenahar> | ||||
| Severity: | medium | Docs Contact: | |||||
| Priority: | medium | ||||||
| Version: | 4.2.1 | CC: | amureini, bugs, tnisan, ylavi | ||||
| Target Milestone: | ovirt-4.2.1 | Keywords: | Reopened | ||||
| Target Release: | --- | Flags: | rule-engine:
ovirt-4.2+
ylavi: exception+ |
||||
| Hardware: | x86_64 | ||||||
| OS: | Unspecified | ||||||
| Whiteboard: | |||||||
| Fixed In Version: | ovirt-engine-4.2.1.2 | Doc Type: | If docs needed, set a value | ||||
| Doc Text: | Story Points: | --- | |||||
| Clone Of: | Environment: | ||||||
| Last Closed: | 2018-02-12 11:49:54 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: | |||||||
| Attachments: |
|
||||||
When an image is cold-moved, the structure is replicated to the destination domain by a bunch of CreateSnapshotVDSCommand calls, and then the data is synched from source to dest. There is no snapshot creation in the logs (despite the less than brilliant command name). Allon, does it mean that CreateSnapshotVDSCommand doesn't create a snapshot? It's very confusing (In reply to Elad from comment #2) > Allon, does it mean that CreateSnapshotVDSCommand doesn't create a snapshot? > It's very confusing CreateSnapshotVDSCommand was introduced in the early days of the engine (3.0 IIRC), when the only flow that created a volume (without creating an entire image) was taking a snapshot. It was a bad name back in the day (since it mixed levels of functionality), and nowadays is downright confusing, as you mentioned, since it's being used for other flows too (like cold moving a disk). While there isn't any functional problem (as I noted in comment 1, no redundant snapshot is created), it does generate a very confusing log as you noted in comment 2. I think we can rename this command without breaking anything to help make the log clearer. I'm reopening this BZ and repurposing it for this renaming (priority and severity adjusted accordingly), and will post a patch to hopefully do so for 4.2.2. If the upstream review process deems this patch to be too risky we'll rethink and retarget. Disk cold move now involves CreateVolume instead of CreateSnapshot
2018-01-29 13:17:18,510+02 INFO [org.ovirt.engine.core.bll.storage.disk.MoveDiskCommand] (default task-1) [e0159d45-30f0-45e2-8e2b-4587c917fa7d] Running command: MoveDiskCommand internal: false. Entities affect
ed : ID: 0b1811a6-37aa-43e8-a72c-d5118a4499e3 Type: DiskAction group CONFIGURE_DISK_STORAGE with role type USER
2018-01-29 13:17:21,414+02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateVolumeVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-96) [e0159d45-30f0-45e2-8e2b-4587c917fa7d] START, CreateVolumeV
DSCommand( CreateVolumeVDSCommandParameters:{storagePoolId='aa0b1185-8bf0-4ca4-978b-c6b7df55140c', ignoreFailoverLimit='false', storageDomainId='db01428b-6609-4599-8ca5-ce78fe5f4a74', imageGroupId='0b1811a6-37aa
-43e8-a72c-d5118a4499e3', imageSizeInBytes='1073741824', volumeFormat='RAW', newImageId='600809ab-0e38-4bb2-8966-d0af986d0705', imageType='Preallocated', newImageDescription='null', imageInitialSizeInBytes='0',
imageId='00000000-0000-0000-0000-000000000000', sourceImageGroupId='00000000-0000-0000-0000-000000000000'}), log id: 24497fcb
Used:
rhvm-4.2.1.3-0.1.el7.noarch
This bugzilla is included in oVirt 4.2.1 release, published on Feb 12th 2018. Since the problem described in this bug report should be resolved in oVirt 4.2.1 release, it has been closed with a resolution of CURRENT RELEASE. If the solution does not work for you, please open a new bug report. |
Created attachment 1380980 [details] engine and vdsm logs from 4.2 and 4.1 Description of problem: CreateSnapshotVDSCommand is initiated as past of MoveDiskCommand This seems to be happening for a while as it occurs on both RHV 4.2 and 4.1.7.6 Version-Release number of selected component (if applicable): rhvm-4.2.1-0.2.el7.noarch vdsm-4.20.11-1.el7ev.x86_64 rhevm-4.1.7.6-0.1.el7.noarch vdsm-4.19.36-1.el7ev.x86_64 How reproducible: Always Steps to Reproduce: 1. Create a VM with disk attached 2. While the VM is down, move the disk to a different domain 3. Actual results: Snapshot creation is initiated as part of disk cold move: 4.2: 2018-01-14 13:30:51,365+02 INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-54) [9f6bdd3e-6f7c-4d22-8dd9-11134186d76a] Command 'MoveImageGroup' (id: 'ab682ed0-5a56-4459-91ff-faffd1f0b166') waiting on child command id: '752855d2-38d3-4a03-8daa-089df3fd8957' type:'CopyImageGroupWithData' to complete 2018-01-14 13:30:51,368+02 INFO [org.ovirt.engine.core.bll.storage.disk.image.CloneImageGroupVolumesStructureCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-54) [9f6bdd3e-6f7c-4d22-8dd9-11134186d76a] Starting child command 1 of 1, image '84852761-6715-442b-9735-1fb6070abd13' 2018-01-14 13:30:51,408+02 INFO [org.ovirt.engine.core.bll.storage.disk.image.CreateVolumeContainerCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-54) [9f6bdd3e-6f7c-4d22-8dd9-11134186d76a] Running command: CreateVolumeContainerCommand internal: true. 2018-01-14 13:30:51,435+02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-54) [9f6bdd3e-6f7c-4d22-8dd9-11134186d76a] START, CreateSnapshotVDSCommand( CreateSnapshotVDSCommandParameters:{storagePoolId='6ccfd104-5f57-4a83-a24d-9d7a5a5c92c8', ignoreFailoverLimit='false', storageDomainId='28f3176f-a7a8-499f-83f7-ee0404977e7b', imageGroupId='30aaab0b-01b1-455c-82b0-9a47b065726b', imageSizeInBytes='1073741824', volumeFormat='RAW', newImageId='84852761-6715-442b-9735-1fb6070abd13', imageType='Preallocated', newImageDescription='null', imageInitialSizeInBytes='0', imageId='00000000-0000-0000-0000-000000000000', sourceImageGroupId='00000000-0000-0000-0000-000000000000'}), log id: 6a24f12d 4.1: 2018-01-14 13:32:07,795+02 INFO [org.ovirt.engine.core.bll.storage.disk.image.MoveImageGroupCommand] (org.ovirt.thread.pool-6-thread-3) [55344af7-15fd-41c3-bceb-8c69c2cb9200] Running command: MoveImageGroupComm and internal: true. Entities affected : ID: daf92ffc-1108-4b64-9a96-1f5d13c449fb Type: Storage 2018-01-14 13:32:08,001+02 INFO [org.ovirt.engine.core.bll.storage.disk.image.CopyImageGroupWithDataCommand] (org.ovirt.thread.pool-6-thread-3) [55344af7-15fd-41c3-bceb-8c69c2cb9200] Running command: CopyImageG roupWithDataCommand internal: true. 2018-01-14 13:32:08,208+02 INFO [org.ovirt.engine.core.bll.storage.disk.image.CloneImageGroupVolumesStructureCommand] (org.ovirt.thread.pool-6-thread-3) [55344af7-15fd-41c3-bceb-8c69c2cb9200] Running command: C loneImageGroupVolumesStructureCommand internal: true. 2018-01-14 13:32:08,371+02 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-3) [55344af7-15fd-41c3-bceb-8c69c2cb9200] EVENT_ID: USER_MOVED_DISK(2,008), Correlation ID: 55344af7-15fd-41c3-bceb-8c69c2cb9200, Job ID: 953f4703-3265-42a5-89c3-e3039ac48242, Call Stack: null, Custom ID: null, Custom Event ID: -1, Message: User admin@internal-authz moving disk test_Di sk1 to domain nested_storage_nfs. 2018-01-14 13:32:08,521+02 INFO [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler9) [55344af7-15fd-41c3-bceb-8c69c2cb9200] Command 'CopyImageGroupWithData' (id: 'b2997a47- eff9-478a-8467-d6e643153401') waiting on child command id: '6f089dd2-0dda-4bd2-9782-3a5be23facfd' type:'CloneImageGroupVolumesStructure' to complete 2018-01-14 13:32:08,526+02 INFO [org.ovirt.engine.core.bll.storage.disk.image.CloneImageGroupVolumesStructureCommand] (DefaultQuartzScheduler9) [55344af7-15fd-41c3-bceb-8c69c2cb9200] Starting child command 1 of 1, image 'e4bd9ca7-0d33-4050-abd4-98e6c977db54' 2018-01-14 13:32:08,644+02 INFO [org.ovirt.engine.core.bll.storage.disk.image.CreateVolumeContainerCommand] (DefaultQuartzScheduler9) [55344af7-15fd-41c3-bceb-8c69c2cb9200] Running command: CreateVolumeContaine rCommand internal: true. 2018-01-14 13:32:08,686+02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (DefaultQuartzScheduler9) [55344af7-15fd-41c3-bceb-8c69c2cb9200] START, CreateSnapshotVDSCommand( CreateSnaps hotVDSCommandParameters:{runAsync='true', storagePoolId='d633f884-45f6-4f9e-884d-85821cefd033', ignoreFailoverLimit='false', storageDomainId='daf92ffc-1108-4b64-9a96-1f5d13c449fb', imageGroupId='afee9cb2-9a1e-4b 58-a24f-4ef18f254fe7', imageSizeInBytes='1073741824', volumeFormat='RAW', newImageId='e4bd9ca7-0d33-4050-abd4-98e6c977db54', imageType='Sparse', newImageDescription='null', imageInitialSizeInBytes='0', imageId=' 00000000-0000-0000-0000-000000000000', sourceImageGroupId='00000000-0000-0000-0000-000000000000'}), log id: 51ad2df6 Expected results: Cold disk move should not trigger snapshot creation. Additional info: engine and vdsm logs from 4.2 and 4.1