ViPR Controller: Volume creation on VNX fails
Summary: ViPR Controller: Volume creation on VNX fails
This article applies to
This article does not apply to
This article is not tied to any specific product.
Not all product versions are identified in this article.
Symptoms
This issue occurs after users upgrade VNX Operating Environment code to: VNX: 05.33.009.5.217
This issue has also been observed at 05.33.009.5.231 without the hotfix.
The user is unable to create a volume on VNX.
The order fails intermittently but on a regular basis.
Issue persists after running refsys, rebooting the SMI-S Server, and restarting ECOM.
The volume remains on array after failure. Resubmitting the order will fail using the same volume name.
ViPR Controller UI error
[ERROR] Wed Aug 29 10:58:09 UTC 2018 Error 16000: Message: The job has failed: Caught an exception while trying to update volume attributes:
The requested object cannot be found. (com.emc.cmp.osls.se.osl.Device.StorDevShow():280 C:ERROR_CLASS_SOFTWARE F:ERROR_FAMILY_NOT_FOUND R:1000052 L:2 C:ERROR_CLASS_SOFTWARE F:ERROR_FAMILY_NOT_FOUND R:1000052 No objects of the requested type were found : 2 : 7 : "The device name specified could not be found")
Note:
Also reference the following KB article:
523574 : ViPR Controller: ViPR Controller use of Solutions Enabler 7.6.2.102 / SMI-S 4.6.2.30 requires an RPQ https://support.emc.com/kb/523574 (Level 40 article)
Cause
After SMI-S reports that the volume has been successfully created, ViPR C queries SMI-S to gather information about the volume to update the ViPR C database. SMI-S is unable to provide this information when requested.
Since the volume information is not provided by SMI-S, ViPR Controller's rollback does not remove the volume from the array.
Since the volume information is not provided by SMI-S, ViPR Controller's rollback does not remove the volume from the array.
Resolution
Resolution:
After verifying the ViPR Controller UI error shown in the Issue section above, open a Service Request with the Remote Proactive (RCM): Unified Technical Support group
for each VNX to be upgraded requesting VNX HotFix ManagementServer_1.3.9.1.0306-1.upf (ref. AR 958882) including justification for why the hotfix is needed and the
current VNX Array Model, VNX Block OE, Solutions Enabler, SMI-S, and ViPR Controller versions. See Notes below.
Additional Information
NOTE: When volume creation fails , the backend volume is left in place and will need to be manually removed from the array.
ViPR C logs
ViPR C issues command to create volume:
vipr2 vipr2 controllersvc 2018-09-03 14:25:31,763 [1684|createVolumes|39a39976-b004-45e9-98c7-f1e463d25517c83c9b0f-fe18-485b-85c3-cdd8b25f2a8d] INFO SmisStorageDevice.java (line 226) Create Volume Start - Array:CKM<CLARiiON Serial Number removed>, Pool:CLARIION+CKM<CLARiiON Serial Number removed>+POOL+<Pool Name removed>
Volume:<Volume Name removed> , IsThinlyProvisioned: true
vipr2 vipr2 controllersvc 2018-09-03 14:25:31,776 [1684|createVolumes|39a39976-b004-45e9-98c7-f1e463d25517c83c9b0f-fe18-485b-85c3-cdd8b25f2a8d] INFO SmisCommandHelper.java (line 201)
SMI-S Provider: <SMI-S Provider FQDN removed> -- Attempting invokeMethod CreateOrModifyElementFromStoragePool on objectPath=/root/emc:Clar_StorageConfigurationService.CreationClassName="Clar_StorageConfigurationService",Name="EMCStorageConfigurationService",SystemCreationClassName="Clar_StorageSystem",SystemName="CLARiiON+CKM<CLARiiON Serial Number removed>" with arguments:
inArg[0]=uint16 ElementType = 5;
inArg[1]=Clar_UnifiedStoragePool ref InPool = "root/emc:Clar_UnifiedStoragePool.InstanceID=\"CLARiiON+CKM<CLARiiON Serial Number removed>+<Pool Name removed>\"";
inArg[2]=uint64 Size = 10737418240;
inArg[3]=uint32 EMCNumberOfDevices = 1;
inArg[4]=string ElementName = "<Volume Name removed>";
inArg[5]=Clar_StoragePoolSetting ref Goal = "root/emc:Clar_StoragePoolSetting.InstanceID=\"CLARiiON+CKM<CLARiiON Serial Number removed>+D+T+3031128139+<Pool Name removed>\"";
Volume:<Volume Name removed> , IsThinlyProvisioned: true
vipr2 vipr2 controllersvc 2018-09-03 14:25:31,776 [1684|createVolumes|39a39976-b004-45e9-98c7-f1e463d25517c83c9b0f-fe18-485b-85c3-cdd8b25f2a8d] INFO SmisCommandHelper.java (line 201)
SMI-S Provider: <SMI-S Provider FQDN removed> -- Attempting invokeMethod CreateOrModifyElementFromStoragePool on objectPath=/root/emc:Clar_StorageConfigurationService.CreationClassName="Clar_StorageConfigurationService",Name="EMCStorageConfigurationService",SystemCreationClassName="Clar_StorageSystem",SystemName="CLARiiON+CKM<CLARiiON Serial Number removed>" with arguments:
inArg[0]=uint16 ElementType = 5;
inArg[1]=Clar_UnifiedStoragePool ref InPool = "root/emc:Clar_UnifiedStoragePool.InstanceID=\"CLARiiON+CKM<CLARiiON Serial Number removed>+<Pool Name removed>\"";
inArg[2]=uint64 Size = 10737418240;
inArg[3]=uint32 EMCNumberOfDevices = 1;
inArg[4]=string ElementName = "<Volume Name removed>";
inArg[5]=Clar_StoragePoolSetting ref Goal = "root/emc:Clar_StoragePoolSetting.InstanceID=\"CLARiiON+CKM<CLARiiON Serial Number removed>+D+T+3031128139+<Pool Name removed>\"";
..
Returned: 4096 with output arguments:
outArg=uint64 Size = 10737418240;
outArg=SE_ConcreteJob ref Job = "root/emc:SE_ConcreteJob.InstanceID=\"<1234567890>\"";
Execution time: 0.591798 seconds.
SMI-S Provider Logs:
SMI-S receives the order and provides a concrete id.
Returned: 4096 with output arguments:
outArg=uint64 Size = 10737418240;
outArg=SE_ConcreteJob ref Job = "root/emc:SE_ConcreteJob.InstanceID=\"<1234567890>\"";
Execution time: 0.591798 seconds.
SMI-S Provider Logs:
SMI-S receives the order and provides a concrete id.
Mon Sep 03 16:25:29 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 2013263616 global DEBUG SE_StorageHardwareID.cpp 414 : Store the array id in the context to scope populate: NS_CMP_OSLS_SE_ARRAY_FUNC::SE_StorageHardwareID::ContextArrayId
Mon Sep 03 16:25:31 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 2013263616 StorageConfigurationService.BlockServices DEBUG EMC_StorageConfigurationService.cpp 1887 : Element size: 10737418240
Mon Sep 03 16:25:31 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 2013263616 global DEBUG 163 : OslCache missing cache entry for array <Array type="CLARiiON" encoding="String" value="CKM<CLARiiON Serial Number removed>" />
Mon Sep 03 16:25:32 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 2013263616 global INFO Job.cpp 459 : Job <1234567890> Submitted
Mon Sep 03 16:25:32 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 2013263616 StorageConfigurationService.BlockServices DEBUG EMC_StorageConfigurationService.cpp 2705 : Submit jobId <1234567890> to run asynchronously
Mon Sep 03 16:25:32 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 2013263616 JobControl INFO JobTableMonitor.cpp 61 : Job table monitor started.
Mon Sep 03 16:25:32 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 -1272031488 JobControl DEBUG JobTableMonitor.cpp 88 : Job table monitor started.
Mon Sep 03 16:25:32 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 2013263616 JobControl DEBUG JobTable.cpp 107 : Added to job table job id: <1234567890>
Mon Sep 03 16:25:32 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 -1269930240 BlockServices.JobControlVolume DEBUG JOB_VolCreate.cpp 400 : Create Storage Volume Job Id:<1234567890>
Mon Sep 03 16:25:32 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 2013263616 JobControl INFO JobControl.cpp 86 : Started job: <1234567890>
Mon Sep 03 16:25:31 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 2013263616 StorageConfigurationService.BlockServices DEBUG EMC_StorageConfigurationService.cpp 1887 : Element size: 10737418240
Mon Sep 03 16:25:31 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 2013263616 global DEBUG 163 : OslCache missing cache entry for array <Array type="CLARiiON" encoding="String" value="CKM<CLARiiON Serial Number removed>" />
Mon Sep 03 16:25:32 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 2013263616 global INFO Job.cpp 459 : Job <1234567890> Submitted
Mon Sep 03 16:25:32 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 2013263616 StorageConfigurationService.BlockServices DEBUG EMC_StorageConfigurationService.cpp 2705 : Submit jobId <1234567890> to run asynchronously
Mon Sep 03 16:25:32 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 2013263616 JobControl INFO JobTableMonitor.cpp 61 : Job table monitor started.
Mon Sep 03 16:25:32 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 -1272031488 JobControl DEBUG JobTableMonitor.cpp 88 : Job table monitor started.
Mon Sep 03 16:25:32 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 2013263616 JobControl DEBUG JobTable.cpp 107 : Added to job table job id: <1234567890>
Mon Sep 03 16:25:32 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 -1269930240 BlockServices.JobControlVolume DEBUG JOB_VolCreate.cpp 400 : Create Storage Volume Job Id:<1234567890>
Mon Sep 03 16:25:32 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 2013263616 JobControl INFO JobControl.cpp 86 : Started job: <1234567890>
SMI-S logs:
SMI-S reports that volume creation is complete:
Mon Sep 03 16:28:02 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 -1269930240 BlockServices.JobControlVolume DEBUG JOB_VolCreate.cpp 621 : Completed performImmediateSync().
Mon Sep 03 16:28:02 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 -1269930240 BlockServices.JobControlVolume DEBUG JOB_VolCreate.cpp 1891 : Completed performImmediateSync().
Mon Sep 03 16:28:02 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 -1269930240 BlockServices.JobControlVolume INFO JOB_VolCreate.cpp 1908 : Created volume: <Device name="<DeviceID replaced 12345>" />
Mon Sep 03 16:28:02 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 -1269930240 global INFO Job.cpp 584 : Marked job 100% completed, Job id: <1234567890>
Mon Sep 03 16:28:02 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 -1269930240 BlockServices.JobControlVolume DEBUG JOB_VolCreate.cpp 1891 : Completed performImmediateSync().
Mon Sep 03 16:28:02 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 -1269930240 BlockServices.JobControlVolume INFO JOB_VolCreate.cpp 1908 : Created volume: <Device name="<DeviceID replaced 12345>" />
Mon Sep 03 16:28:02 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 -1269930240 global INFO Job.cpp 584 : Marked job 100% completed, Job id: <1234567890>
ViPR logs:
ViPR logs indicate that the SMI-S job is complete:
vipr2 vipr2 controllersvc 2018-09-03 14:28:02,394 [pool-58-thread-1] INFO SmisJob.java (line 178) SmisJob: Looking up job: id <1234567890>, provider: <SMI-S Provider FQDN removed>
vipr2 vipr2 controllersvc 2018-09-03 14:28:02,413 [pool-58-thread-1] INFO SmisJob.java (line 197) Status value[0]: 17
vipr2 vipr2 controllersvc 2018-09-03 14:28:02,413 [pool-58-thread-1] INFO SmisJob.java (line 197) Status value[1]: 2
vipr2 vipr2 controllersvc 2018-09-03 14:28:02,413 [pool-58-thread-1] INFO SmisJob.java (line 200) SmisJob: <1234567890> succeeded
vipr2 vipr2 controllersvc 2018-09-03 14:28:02,413 [pool-58-thread-1] INFO SmisJob.java (line 243) SmisJob: Post processing job: id <1234567890>, provider: <SMI-S Provider FQDN removed>
vipr2 vipr2 controllersvc 2018-09-03 14:28:02,413 [pool-58-thread-1] INFO SmisJob.java (line 197) Status value[0]: 17
vipr2 vipr2 controllersvc 2018-09-03 14:28:02,413 [pool-58-thread-1] INFO SmisJob.java (line 197) Status value[1]: 2
vipr2 vipr2 controllersvc 2018-09-03 14:28:02,413 [pool-58-thread-1] INFO SmisJob.java (line 200) SmisJob: <1234567890> succeeded
vipr2 vipr2 controllersvc 2018-09-03 14:28:02,413 [pool-58-thread-1] INFO SmisJob.java (line 243) SmisJob: Post processing job: id <1234567890>, provider: <SMI-S Provider FQDN removed>
SMI-S logs:
After the volume was successfully created, ViPR Controller queries SMI-S to update the database, but SMI-S is unable to provided details on the volume.
Mon Sep 03 16:28:03 +0200 2018 <SMI-S Provider Name removed> ECOM 26037 -1269930240 global DEBUG 307 : StorDevShow() failed with handle="65537", arrayId="<Array type="CLARiiON" encoding="String" value="CKM<CLARiiON Serial Number removed>" />", deviceId="<Device name="<DeviceID replaced 12345>" />", mask="4079755".
ViPR logs:
This error is passed to ViPR C from SMI-S and the order fails. Since the volume was not found when querying SMI-S the volume is not removed from the array on rollback:
vipr2 vipr2 controllersvc 2018-09-03 14:28:03,081 [pool-58-thread-1] ERROR SmisAbstractCreateVolumeJob.java (line 331) Caught an exception while trying to update attributes for volume <Volume Name removed> (<Volume URN removed>) and volume path //<IP Address removed>/root/emc:Clar_StorageVolume.CreationClassName="Clar_StorageVolume",DeviceID="<DeviceID replaced 12345>",SystemCreationClassName="Clar_StorageSystem",SystemName="CLARiiON+CKM<CLARiiON Serial Number removed>"
WBEMException: CIM_ERR_NOT_FOUND (The requested object cannot be found. (com.emc.cmp.osls.se.osl.Device.StorDevShow():280 C:ERROR_CLASS_SOFTWARE F:ERROR_FAMILY_NOT_FOUND R:1000052 L:2 C:ERROR_CLASS_SOFTWARE F:ERROR_FAMILY_NOT_FOUND R:1000052 No objects of the requested type were found : 2 : 7 : "The device name specified could not be found"))
at org.sblim.cimclient.internal.wbem.CloseableIteratorSAX.hasNext(CloseableIteratorSAX.java:121)
at org.sblim.cimclient.internal.wbem.WBEMClientCIMXML.getIterator(WBEMClientCIMXML.java:2134)
at org.sblim.cimclient.internal.wbem.WBEMClientCIMXML.getInstance(WBEMClientCIMXML.java:1257)
at com.emc.storageos.volumecontroller.impl.smis.job.SmisAbstractCreateVolumeJob.commonVolumeUpdate(SmisAbstractCreateVolumeJob.java:311)
at com.emc.storageos.volumecontroller.impl.smis.job.SmisAbstractCreateVolumeJob.processVolume(SmisAbstractCreateVolumeJob.java:219)
at com.emc.storageos.volumecontroller.impl.smis.job.SmisAbstractCreateVolumeJob.updateStatus(SmisAbstractCreateVolumeJob.java:120)
at com.emc.storageos.volumecontroller.impl.smis.job.SmisJob.poll(SmisJob.java:246)
at com.emc.storageos.volumecontroller.impl.job.QueueJobTracker.run(QueueJobTracker.java:90)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
vipr2 vipr2 controllersvc 2018-09-03 14:28:03,097 [pool-58-thread-1] INFO SmisAbstractCreateVolumeJob.java (line 372) Skipping step addVolumesToConsistencyGroup: volumes [<Volume URN removed>] do not reference a consistency group.
vipr2 vipr2 controllersvc 2018-09-03 14:28:03,097 [pool-58-thread-1] INFO SmisAbstractCreateVolumeJob.java (line 158) Updating status of job 39a39976-b004-45e9-98c7-f1e463d25517c83c9b0f-fe18-485b-85c3-cdd8b25f2a8d to SUCCESS
Created volume successfully .. NativeId: <DeviceID replaced 12345>, URI: <Volume URN removed>
vipr2 vipr2 controllersvc 2018-09-03 14:28:03,101 [pool-58-thread-1] INFO VolumeTaskCompleter.java (line 106) opType: CREATE_BLOCK_VOLUME detail: VolumeCreateFailed:Volume is created.
vipr2 vipr2 controllersvc 2018-09-03 14:28:03,103 [pool-58-thread-1] INFO VolumeTaskCompleter.java (line 82) Bourne VolumeCreateFailed event recorded for Volume <Volume URN removed>
vipr2 vipr2 controllersvc 2018-09-03 14:28:03,126 [pool-58-thread-1] INFO WorkflowService.java (line 653) Updating workflow step: 39a39976-b004-45e9-98c7-f1e463d25517c83c9b0f-fe18-485b-85c3-cdd8b25f2a8d state ERROR : The job has failed: Caught an exception while trying to update volume attributes: The requested object cannot be found. (com.emc.cmp.osls.se.osl.Device.StorDevShow():280 C:ERROR_CLASS_SOFTWARE F:ERROR_FAMILY_NOT_FOUND R:1000052 L:2 C:ERROR_CLASS_SOFTWARE F:ERROR_FAMILY_NOT_FOUND R:1000052 No objects of the requested type were found : 2 : 7 : "The device name specified could not be found")
WBEMException: CIM_ERR_NOT_FOUND (The requested object cannot be found. (com.emc.cmp.osls.se.osl.Device.StorDevShow():280 C:ERROR_CLASS_SOFTWARE F:ERROR_FAMILY_NOT_FOUND R:1000052 L:2 C:ERROR_CLASS_SOFTWARE F:ERROR_FAMILY_NOT_FOUND R:1000052 No objects of the requested type were found : 2 : 7 : "The device name specified could not be found"))
at org.sblim.cimclient.internal.wbem.CloseableIteratorSAX.hasNext(CloseableIteratorSAX.java:121)
at org.sblim.cimclient.internal.wbem.WBEMClientCIMXML.getIterator(WBEMClientCIMXML.java:2134)
at org.sblim.cimclient.internal.wbem.WBEMClientCIMXML.getInstance(WBEMClientCIMXML.java:1257)
at com.emc.storageos.volumecontroller.impl.smis.job.SmisAbstractCreateVolumeJob.commonVolumeUpdate(SmisAbstractCreateVolumeJob.java:311)
at com.emc.storageos.volumecontroller.impl.smis.job.SmisAbstractCreateVolumeJob.processVolume(SmisAbstractCreateVolumeJob.java:219)
at com.emc.storageos.volumecontroller.impl.smis.job.SmisAbstractCreateVolumeJob.updateStatus(SmisAbstractCreateVolumeJob.java:120)
at com.emc.storageos.volumecontroller.impl.smis.job.SmisJob.poll(SmisJob.java:246)
at com.emc.storageos.volumecontroller.impl.job.QueueJobTracker.run(QueueJobTracker.java:90)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
vipr2 vipr2 controllersvc 2018-09-03 14:28:03,097 [pool-58-thread-1] INFO SmisAbstractCreateVolumeJob.java (line 372) Skipping step addVolumesToConsistencyGroup: volumes [<Volume URN removed>] do not reference a consistency group.
vipr2 vipr2 controllersvc 2018-09-03 14:28:03,097 [pool-58-thread-1] INFO SmisAbstractCreateVolumeJob.java (line 158) Updating status of job 39a39976-b004-45e9-98c7-f1e463d25517c83c9b0f-fe18-485b-85c3-cdd8b25f2a8d to SUCCESS
Created volume successfully .. NativeId: <DeviceID replaced 12345>, URI: <Volume URN removed>
vipr2 vipr2 controllersvc 2018-09-03 14:28:03,101 [pool-58-thread-1] INFO VolumeTaskCompleter.java (line 106) opType: CREATE_BLOCK_VOLUME detail: VolumeCreateFailed:Volume is created.
vipr2 vipr2 controllersvc 2018-09-03 14:28:03,103 [pool-58-thread-1] INFO VolumeTaskCompleter.java (line 82) Bourne VolumeCreateFailed event recorded for Volume <Volume URN removed>
vipr2 vipr2 controllersvc 2018-09-03 14:28:03,126 [pool-58-thread-1] INFO WorkflowService.java (line 653) Updating workflow step: 39a39976-b004-45e9-98c7-f1e463d25517c83c9b0f-fe18-485b-85c3-cdd8b25f2a8d state ERROR : The job has failed: Caught an exception while trying to update volume attributes: The requested object cannot be found. (com.emc.cmp.osls.se.osl.Device.StorDevShow():280 C:ERROR_CLASS_SOFTWARE F:ERROR_FAMILY_NOT_FOUND R:1000052 L:2 C:ERROR_CLASS_SOFTWARE F:ERROR_FAMILY_NOT_FOUND R:1000052 No objects of the requested type were found : 2 : 7 : "The device name specified could not be found")
Products
SMI-S Provider, VNX2 SeriesArticle Properties
Article Number: 000167258
Article Type: Solution
Last Modified: 15 Sep 2025
Version: 5
Find answers to your questions from other Dell users
Support Services
Check if your device is covered by Support Services.