Long story short we have a clone of our production database that we refresh and remount on a linux server every night.  This is a script that is being called from cron.  We recently converted the server that runs this script from a physical server to a vmware vm.  Since we have done that this refresh process has failed the past 3 sunday nights.  It runs every single night and it runs without errors every other night.

There's not much to the script, here's the command that creates the flex clone:

snapdrive snap connect -lun log/disk disk_$LUN -snapname filer:/vol/database_volume/log/disk:$SNAPNAME

them we mount the flex clone that is create via iSCSI.

The error that is being reported by the script is:

385  connecting filer:/vol/database_volume/log/disk:     386     creating unrestricted volume clone filer:/vol/clone_volume ... failure     387 0002-098 Admin error: Failed to create volume clone clone_volume on filer filer : The volume is not currently available

The error from the sd-trace.log:

173338 00:30:54 02/26/12 [f7f61b90]i,2,18,FilerZephyr::volume_clone_create: zapi filer root "" volume-clone-create parent-snapsho        t daily-2012-02-26 parent-volume database_volume space-reserve none volume planningdb_rootdb_log  173339 00:30:54 02/26/12 [f7f61b90]i,2,18,FilerZephyr::volume_clone_create in = <volume-clone-create>  173340         <parent-volume>database_volume</parent-volume>  173341         <parent-snapshot>daily-2012-02-26</parent-snapshot>  173342         <volume>clone_volume</volume>  173343         <space-reserve>none</space-reserve>  173344 </volume-clone-create>  173345   173346 00:30:54 02/26/12 [f7f61b90]i,2,18,FilerZephyr::output in = <results reason="The volume is not currently available" statu        s="failed" errno="13156"/>  173347   173348 00:30:54 02/26/12 [f7f61b90]E,2,18,FilerZephyr:: (filer) volume-clone-create failed, error: 13156: The volume is not currently available

And then what's odd is if you look at the messages file on the filer, it's reporting as if the clone was successfully created:

Sun Feb 26 00:29:28 MST [filer: wafl.snap.delete:info]: Snapshot copy 2012-02-24 07_00_27 daily_filer_database_volume.-.log on volume database_volume NetApp was deleted by the Data ONTAP function zapi_snapshot_delete. The unique ID for this Snapshot copy is (111, 4139408). Sun Feb 26 00:30:56 MST [filer: wafl.volume.clone.created:info]: Volume clone clone_volume of volume database_volume was created successfully. Sun Feb 26 00:30:56 MST [filer: lun.newLocation.offline:warning]: LUN /vol/clone_volume/log/disk has been taken offline to prevent map conflicts after a copy or move operation. Sun Feb 26 00:30:56 MST [filer: lun.map:info]: LUN /vol/clone_volume/disk was mapped to initiator group linux-server.domain.com_iscsi_SdIg=0

The only thing I'm wondering is if that zapi_snapshot_delete that is happening 1 second before could be causing an issue however I looked at the logs from the past sunday failure and that zapi_snapshot_delete did not happen at the same time so I'm not sure that's the issue.

Any help would be really appreciated.

Thanks, Dan