Bug 1185615

Summary: NPE in AddDiskCommand during ovf volume creation.
Product: [Retired] oVirt Reporter: Vered Volansky <vered>
Component: ovirt-engine-coreAssignee: Doron Fediuck <dfediuck>
Status: CLOSED CURRENTRELEASE QA Contact: Kevin Alon Goldblatt <kgoldbla>
Severity: urgent Docs Contact:
Priority: unspecified    
Version: 3.5CC: amureini, bugs, daniel.helgenberger, dfediuck, ecohen, gklein, kgoldbla, laravot, lsurette, rbalakri, rgolan, sbonazzo, yeylon
Target Milestone: ---Keywords: Reopened
Target Release: 3.5.1   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard: sla
Fixed In Version: ovirt-3.5.1.1 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-09-04 12:47:32 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: SLA RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1193058, 1196662, 1197441    
Attachments:
Description Flags
engine log none

Description Vered Volansky 2015-01-25 09:26:33 UTC 
Description of problem:
Failed creation of OVF volume.
NPE in log.

audit log message:

Failed to create OVF store disk for Storage Domain lun1. OVF data won't be updated meanwhile for that domain.

Version-Release number of selected component (if applicable):
master - a22f24e3480726ae05bdd40712840ee0a0f284b4

Steps to Reproduce:
1. Created a new iscsi storage domain.

Further operations were probably not related bug were:
Add a new vm, add a new preallocated disk to that VM and move the disk to a pre-existing domain.

Actual results:
Succeeded, NPE caught my eye later on.

Additional info:
Log:
2015-01-25 11:01:23,224 INFO  [org.ovirt.engine.core.bll.CreateOvfVolumeForStorageDomainCommand] (DefaultQuartzScheduler_Worker-46) [4b8aa4aa] Running command: CreateOvfVolumeForStorageDomainCommand internal: true. Entities affected :  ID: e9d60390-4977-492d-98f9-267d46ffa317 Type: Storage
2015-01-25 11:01:23,248 ERROR [org.ovirt.engine.core.bll.AddDiskCommand] (DefaultQuartzScheduler_Worker-46) [22f4adfc] Error during CanDoActionFailure.: java.lang.NullPointerException
	at org.ovirt.engine.core.bll.profiles.DiskProfileHelper.isDiskProfilePermitted(DiskProfileHelper.java:95) [bll.jar:]
	at org.ovirt.engine.core.bll.profiles.DiskProfileHelper.updateDiskProfileForBackwardCompatibility(DiskProfileHelper.java:83) [bll.jar:]
	at org.ovirt.engine.core.bll.profiles.DiskProfileHelper.setAndValidateDiskProfiles(DiskProfileHelper.java:56) [bll.jar:]
	at org.ovirt.engine.core.bll.AddDiskCommand.setAndValidateDiskProfiles(AddDiskCommand.java:604) [bll.jar:]
	at org.ovirt.engine.core.bll.AddDiskCommand.canDoAction(AddDiskCommand.java:123) [bll.jar:]
Comment 1 Vered Volansky 2015-01-25 09:31:24 UTC 
Created attachment 983941 [details]
engine log
Comment 2 Roy Golan 2015-01-26 07:20:08 UTC 
Why bypass the DiskProfileHelper and not just fix CreateOvfStoresForStorageDomainCommand to skip permission check?
Comment 3 Gilad Chaplik 2015-01-29 14:52:48 UTC 
@Roy, I'd rather fix the bug for 3.5, we can think about it in 3.6
Comment 4 Sandro Bonazzola 2015-02-02 10:24:02 UTC 
The fix for this issue has been released as ovirt-engine-3.5.1.1 async release.
Comment 5 Eyal Edri 2015-02-26 12:31:34 UTC 
this ovirt bug was fixed during 3.5.1 cycle and is included in the build, and therefore should be verified.
Comment 6 Kevin Alon Goldblatt 2015-03-16 12:49:43 UTC 
Verified with v3.5.1 vt14 as follows:

Created new isci domain
Created VM with 2 disks
Added 3 new disk to VM (OVF disks were created with this step)

From engine log:
-------------------------
2015-03-16 14:36:03,904 INFO  [org.ovirt.engine.core.bll.CreateOvfVolumeForStorageDomainCommand] (DefaultQuartzScheduler_Worker-12) [17376e3d] Running command: CreateOvfVolumeForStorageDomainCommand internal: true. Entities affected :  I
D: 7c5f2e34-cded-44ca-85b9-5c8c197ea6db Type: Storage
2015-03-16 14:36:03,935 INFO  [org.ovirt.engine.core.bll.AddDiskCommand] (DefaultQuartzScheduler_Worker-12) [4b52923a] Running command: AddDiskCommand internal: true. Entities affected :  ID: 7c5f2e34-cded-44ca-85b9-5c8c197ea6db Type: St
orageAction group CREATE_DISK with role type USER
2015-03-16 14:36:03,984 INFO  [org.ovirt.engine.core.bll.AddImageFromScratchCommand] (DefaultQuartzScheduler_Worker-12) [4be7d426] Running command: AddImageFromScratchCommand internal: true. Entities affected :  ID: 7c5f2e34-cded-44ca-85
b9-5c8c197ea6db Type: Storage
2015-03-16 14:36:04,011 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (DefaultQuartzScheduler_Worker-12) [4be7d426] START, CreateImageVDSCommand( storagePoolId = 6d96f52d-d791-4f66-83bd-2553ca0f3012, ignoreFailo
verLimit = false, storageDomainId = 7c5f2e34-cded-44ca-85b9-5c8c197ea6db, imageGroupId = c07655b0-e5a8-4b5f-afc5-82b760b4e130, imageSizeInBytes = 134217728, volumeFormat = RAW, newImageId = b0aba327-85c7-4739-8e32-9e4b3ddf4a24, newImageD
escription = {"DiskAlias":"OVF_STORE","DiskDescription":"OVF_STORE"}), log id: 5603f552
2015-03-16 14:36:04,015 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (DefaultQuartzScheduler_Worker-12) [4be7d426] -- executeIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUI
D
2015-03-16 14:36:04,129 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (DefaultQuartzScheduler_Worker-12) [4be7d426] FINISH, CreateImageVDSCommand, return: b0aba327-85c7-4739-8e32-9e4b3ddf4a24, log id: 5603f552
2015-03-16 14:36:04,131 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-12) [4be7d426] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 03a3a64b-8083-423e-a916-90116ab432db
2015-03-16 14:36:04,131 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (DefaultQuartzScheduler_Worker-12) [4be7d426] CommandMultiAsyncTasks::AttachTask: Attaching task fdf21eba-1b24-4533-a770-95cb1c37e735 to command 03a3a64b-8083-423e-a916-90116ab432db.
2015-03-16 14:36:04,145 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-12) [4be7d426] Adding task fdf21eba-1b24-4533-a770-95cb1c37e735 (Parent Command CreateOvfStoresForStorageDomain, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
2015-03-16 14:36:04,167 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-12) [4be7d426] Correlation ID: 4b52923a, Call Stack: null, Custom Event ID: -1, Message: Add-Disk operation of 'OVF_STORE' was initiated by the system.
2015-03-16 14:36:04,180 INFO  [org.ovirt.engine.core.bll.CreateOvfVolumeForStorageDomainCommand] (DefaultQuartzScheduler_Worker-12) [758b5142] Running command: CreateOvfVolumeForStorageDomainCommand internal: true. Entities affected :  ID: 7c5f2e34-cded-44ca-85b9-5c8c197ea6db Type: Storage
2015-03-16 14:36:04,204 INFO  [org.ovirt.engine.core.bll.AddDiskCommand] (DefaultQuartzScheduler_Worker-12) [1c70ce1d] Running command: AddDiskCommand internal: true. Entities affected :  ID: 7c5f2e34-cded-44ca-85b9-5c8c197ea6db Type: StorageAction group CREATE_DISK with role type USER
2015-03-16 14:36:04,236 INFO  [org.ovirt.engine.core.bll.AddImageFromScratchCommand] (DefaultQuartzScheduler_Worker-12) [40950097] Running command: AddImageFromScratchCommand internal: true. Entities affected :  ID: 7c5f2e34-cded-44ca-85b9-5c8c197ea6db Type: Storage
2015-03-16 14:36:04,251 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (DefaultQuartzScheduler_Worker-12) [40950097] START, CreateImageVDSCommand( storagePoolId = 6d96f52d-d791-4f66-83bd-2553ca0f3012, ignoreFailoverLimit = false, storageDomainId = 7c5f2e34-cded-44ca-85b9-5c8c197ea6db, imageGroupId = 9bb02e1c-ed44-4c7a-acad-be9552e67e22, imageSizeInBytes = 134217728, volumeFormat = RAW, newImageId = 4dbad057-f94c-4833-8443-ce022219348b, newImageDescription = {"DiskAlias":"OVF_STORE","DiskDescription":"OVF_STORE"}), log id: 55f6ee22
2015-03-16 14:36:04,256 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (DefaultQuartzScheduler_Worker-12) [40950097] -- executeIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID
2015-03-16 14:36:04,356 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (DefaultQuartzScheduler_Worker-12) [40950097] FINISH, CreateImageVDSCommand, return: 4dbad057-f94c-4833-8443-ce022219348b, log id: 55f6ee22
2015-03-16 14:36:04,358 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (DefaultQuartzScheduler_Worker-12) [40950097] CommandMultiAsyncTasks::AttachTask: Attaching task cdde6bc0-60b3-4511-a5b0-b42e45bb20bc to command 03a3a64b-8083-423e-a916-90116ab432db.
2015-03-16 14:36:04,375 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-12) [40950097] Adding task cdde6bc0-60b3-4511-a5b0-b42e45bb20bc (Parent Command CreateOvfStoresForStorageDomain, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
2015-03-16 14:36:04,393 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-12) [40950097] Correlation ID: 1c70ce1d, Call Stack: null, Custom Event ID: -1, Message: Add-Disk operation of 'OVF_STORE' was initiated by the system.
2015-03-16 14:36:04,403 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-12) [40950097] BaseAsyncTask::startPollingTask: Starting to poll task fdf21eba-1b24-4533-a770-95cb1c37e735.
2015-03-16 14:36:04,403 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-12) [40950097] BaseAsyncTask::startPollingTask: Starting to poll task cdde6bc0-60b3-4511-a5b0-b42e45bb20bc.
2015-03-16 14:36:04,404 INFO  [org.ovirt.engine.core.bll.ProcessOvfUpdateForStorageDomainCommand] (DefaultQuartzScheduler_Worker-12) [40950097] Lock freed to object EngineLock [exclusiveLocks= key: 7c5f2e34-cded-44ca-85b9-5c8c197ea6db value: STORAGE
, sharedLocks= key: 6d96f52d-d791-4f66-83bd-2553ca0f3012 value: OVF_UPDATE
Comment 8 Sandro Bonazzola 2015-09-04 12:47:32 UTC 
This is an automated message.
oVirt 3.5.4 has been released on September 3rd 2015 and should include the fix for this BZ. Moving to closed current release.