Powershell – ESXcli command timeout at 30 minutes

I am working on a powercli script to loop through each datastore in our environment and reclaim space on the thin provisioned LUNs. All LUNs in the environment are Dell Equal Logic.

vCenter version: 5.5.0_1750787

ESXi version: Dell 5.5-1331820(A01)

The problem I am running into is that exactly 30 minutes after executing the unmap command in the script I get the following error(s):

From PowerCLI:

Message:  An error occurred while communicating with the remote host:
InnerText:
At \\SOMEIP\Share\folder\vmware_unmap_datastore.ps1:96 char:9
+        $RETVAL = $ESXCLI.storage.vmfs.unmap(200, $ds.Name, $null)
+        ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    + CatagoryInfo          : OperationsStopped: (:) [], HostCommunication
    + FullyQualifiedErrorId : VMware.VimAutomation.ViCore.Types.V1.ErrorHandling.HostCommunication

From: ESXi Host vpxa.log:

==> vpxa.log <==
2014-06-30T14:39:51.907Z [7265EB70 error 'vpxavpxaVmomi' opID=60e7b2a5-11]
[VpxaClientAdapter::InvokeCommon] Got exception while invoking executeSoap
on vmodl.reflect.ManagedMethodExecuter:ha-managed-method-executer:
'Operation timed out', backtrace:

--> backtrace[00] rip 13546113
Vmacore::System::Stacktrace::CaptureWork(unsigned int)

--> backtrace[01] rip 1339ea1b
Vmacore::System::SystemFactoryImpl::CreateQuickBacktrace(Vmacore::Ref<Vmacor
e::System::Backtrace>&)

--> backtrace[02] rip 1333fe15 Vmacore::Throwable::Throwable(std::string
const&)

--> backtrace[03] rip 133e7055
Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper::WaitForResponse(long
long, Vmacore::Ref<Vmacore::Http::ClientResponse>&)

--> backtrace[04] rip 133e7596
Vmacore::Http::UserAgentImpl::TimedWaitSendRequest(Vmacore::Http::PendingReq
uestItem*, long long, Vmacore::Ref<Vmacore::Http::ClientResponse>&)

--> backtrace[05] rip 1397276c
Vmomi::SoapStubAdapterImpl::InvokeCommon(Vmomi::MoRef*,
Vmomi::ManagedMethod*, Vmacore::RefVector<Vmomi::Any> const&,
Vmomi::RequestContext*, bool, Vmacore::Ref<Vmomi::Any>&)

--> backtrace[06] rip 13972d78
Vmomi::SoapStubAdapterImpl::Invoke_Task(Vmomi::MoRef*,
Vmomi::ManagedMethod*, Vmacore::RefVector<Vmomi::Any>&,
Vmomi::RequestContext*, Vmacore::Ref<Vmomi::Any>&)

--> backtrace[07] rip 1285a104 /usr/lib/vmware/vpxa/bin/vpxa(+0x245104)
[0x1285a104]

--> backtrace[08] rip 1285a478 /usr/lib/vmware/vpxa/bin/vpxa(+0x245478)
[0x1285a478]

--> backtrace[09] rip 1399f764
Vmomi::StubImpl::_Invoke_Task(Vmomi::ManagedMethod*,
Vmacore::RefVector<Vmomi::Any>&, Vmacore::Ref<Vmomi::Any>&)

--> backtrace[10] rip 13a944e2
Vmomi::Reflect::ManagedMethodExecuterStub::ExecuteSoap(std::string const&,
std::string const&, std::string const&,
Vmomi::DataArray<Vmomi::Reflect::ManagedMethodExecuter::SoapArgument>*,
Vmacore::Ref<Vmomi::Reflect::ManagedMethodExecuter::SoapResult>&)

--> backtrace[11] rip 13a96a54 /lib/libvmomi.so(+0x2c2a54) [0x13a96a54]

--> backtrace[12] rip 1394d2c7
Vmomi::ManagedMethodImpl::Dispatch(Vmomi::ManagedObject*,
Vmacore::RefVector<Vmomi::Any>&, Vmacore::Ref<Vmomi::Any>&)

--> backtrace[13] rip 1394e312
Vmomi::ManagedMethodImpl::Invoke(Vmomi::ManagedObject*,
Vmacore::RefVector<Vmomi::Any>&, Vmacore::Ref<Vmomi::Any>&)

--> backtrace[14] rip 129f05ea /usr/lib/vmware/vpxa/bin/vpxa(+0x3db5ea)
[0x129f05ea]

--> backtrace[15] rip 12a95bab /usr/lib/vmware/vpxa/bin/vpxa(+0x480bab)
[0x12a95bab]

--> backtrace[16] rip 12858f22 /usr/lib/vmware/vpxa/bin/vpxa(+0x243f22)
[0x12858f22]

--> backtrace[17] rip 12a7458d VpxLRO::PreAndBodyStartWork(VpxLRO*)

--> backtrace[18] rip 12a67e41 /usr/lib/vmware/vpxa/bin/vpxa(+0x452e41)
[0x12a67e41]

--> backtrace[19] rip 12a715c5 /usr/lib/vmware/vpxa/bin/vpxa(+0x45c5c5)
[0x12a715c5]

--> backtrace[20] rip 12a76822 VpxLRO::LroMainEntry(VpxLRO*)

--> backtrace[21] rip 12a680a1 /usr/lib/vmware/vpxa/bin/vpxa(+0x4530a1)
[0x12a680a1]

--> backtrace[22] rip 12a714c8 /usr/lib/vmware/vpxa/bin/vpxa(+0x45c4c8)
[0x12a714c8]

--> backtrace[23] rip 12a87df2 VpxLroList::ThreadMainEntry()

--> backtrace[24] rip 1282691b
boost::detail::function::void_function_invoker0<void (*)(),
void>::invoke(boost::detail::function::function_buffer&)

--> backtrace[25] rip 134a76ca
Vmacore::System::ThreadPoolAsio::DoWork(Vmacore::Functor<void, Vmacore::Nil,
Vmacore::Nil, Vmacore::Nil, Vmacore::Nil, Vmacore::Nil, Vmacore::Nil,
Vmacore::Nil> const&, bool)

--> backtrace[26] rip 134a7f08
Vmacore::System::ThreadPoolAsio::DoOrEnqueueWork(Vmacore::System::ThreadPool
Asio::WorkTypeInfo&, Vmacore::Functor<void, Vmacore::Nil, Vmacore::Nil,
Vmacore::Nil, Vmacore::Nil, Vmacore::Nil, Vmacore::Nil, Vmacore::Nil>
const&, int)

--> backtrace[27] rip 134a8170
Vmacore::System::ThreadPoolAsio::HandleWork(Vmacore::System::ThreadPoolAsio:
:WorkType, Vmacore::Functor<void, Vmacore::Nil, Vmacore::Nil, Vmacore::Nil,
Vmacore::Nil, Vmacore::Nil, Vmacore::Nil, Vmacore::Nil> const&)

--> backtrace[28] rip 134b0421
Vmacore::System::ThreadPoolAsioWorkBinder::InvokeWork_0(Vmacore::System::Thr
eadPoolAsio::WorkType, boost::function<void ()> const&)

--> backtrace[29] rip 134abe7a
boost::detail::function::void_function_obj_invoker0<boost::_bi::bind_t<void,
void (*)(Vmacore::System::ThreadPoolAsio::WorkType, boost::function<void ()>
const&),
boost::_bi::list2<boost::_bi::value<Vmacore::System::ThreadPoolAsio::WorkTyp
e>, boost::_bi::value<boost::function<void ()> > > >,
void>::invoke(boost::detail::function::function_buffer&)

--> backtrace[30] rip 134b1efc
boost::asio::detail::completion_handler<boost::function<void ()>
> ::do_complete(boost::asio::detail::task_io_service*,
boost::asio::detail::task_io_service_operation*, boost::system::error_code,
unsigned int)

--> backtrace[31] rip 134af20e
boost::asio::detail::task_io_service::do_one(boost::asio::detail::scoped_loc
k<boost::asio::detail::posix_mutex>&,
boost::asio::detail::task_io_service::idle_thread_info*)

--> backtrace[32] rip 134a6e0c
Vmacore::System::ThreadPoolAsio::RunWorkerThread()

--> backtrace[33] rip 134abed3
boost::detail::function::void_function_obj_invoker0<boost::_bi::bind_t<void,
boost::_mfi::mf0<void, Vmacore::System::ThreadPoolAsio>,
boost::_bi::list1<boost::_bi::value<Vmacore::Ref<Vmacore::System::ThreadPool
Asio> > > >, void>::invoke(boost::detail::function::function_buffer&)

--> backtrace[34] rip 1354fc94
Vmacore::System::ThreadPosixPrivate::ThreadBegin(void*)

--> backtrace[35] rip 12fd4d6a /lib/libpthread.so.0(+0x6d6a) [0x12fd4d6a]

--> backtrace[36] rip 17bcde3e /lib/libc.so.6(clone+0x5e) [0x17bcde3e]

-->

2014-06-30T14:39:51.914Z [7265EB70 info 'commonvpxLro' opID=60e7b2a5-11]
[VpxLRO] -- FINISH task-internal-241280 --  --
vmodl.reflect.ManagedMethodExecuter.executeSoap --

2014-06-30T14:39:51.914Z [7265EB70 info 'Default' opID=60e7b2a5-11] [VpxLRO]
-- ERROR task-internal-241280 --  --
vmodl.reflect.ManagedMethodExecuter.executeSoap:
vmodl.fault.HostCommunication:

--> Result:

--> (vmodl.fault.HostCommunication) {

-->    dynamicType = <unset>,

-->    faultCause = (vmodl.MethodFault) null,

-->    msg = "",

--> }

--> Args:

-->

2014-06-30T14:39:51.914Z [72367B70 error
'SoapAdapter.HTTPService.HttpConnection'] Failed to read header on stream
<io_obj p:0x720a3e30, h:18, <TCP '0.0.0.0:0'>, <TCP '0.0.0.0:0'>>:
N7Vmacore15SystemExceptionE(Connection reset by peer)

I have been unable to find a 30 minute session timeout which I can tweak in the script. I attempted to remove or increase the Web Session Timeout in PowerCLI without success:

Set-PowerCLIConfiguration -WebOperationTimeoutSeconds -1 -Scope Session -Confirm:$false
Set-PowerCLIConfiguration -WebOperationTimeoutSeconds 3600 -Scope Session -Confirm:$false

Any direction or advice on improving the following script would be very helpful:

Clear-Host
$ErrorActionPreference = "Inquire"
$DebugPreference = "Continue"
$VerbosePreference = "Continue"

@"
## vmware_unmap_datastore.ps1 #################################################
Usage:        powershell -ExecutionPolicy Bypass -File ./vmware_unmap_datastore.ps1

Purpose:      Dumps Datastore (in GB): Capacity, Free, and Uncommitted space to
              to CSV and runs ESXCli command 'unmap' to retrieve unused space
              on Thin Provisioned LUNs.

Requirements: Windows Powershell and VI Toolkit

Assumptions:  All ESXi hosts have access to all datastores

TO DO:        Import Dell Equal Logic Module, get Used space before/after unmap

History:      06/20/2014  -  Created
###############################################################################
"@

## Prompt Administrator for vCenter Server ####################################
###############################################################################
[System.Reflection.Assembly]::LoadWithPartialName('Microsoft.VisualBasic') | Out-Null
$VCServer = [Microsoft.VisualBasic.Interaction]::InputBox(
                "vCenter Server FQDN or IP",
                "PowerCLI Prompt: vCenter Server Query",
                "VCENTERHOST.SUB2.SUM1.DOMAIN.COM")


## Filename and path to save the CSV ##########################################
###############################################################################
$timestamp = $(((get-date).ToUniversalTime()).ToString("yyyyMMdd"))
$output_path = [Environment]::GetFolderPath("mydocuments")
$output_file = $output_path + "\datastore_info-" + $timestamp + ".csv"

## Ensure VMware Automation Core Snap In is loaded ############################
###############################################################################
if ((Get-PSSnapin -Name VMware.VimAutomation.Core -ErrorAction SilentlyContinue) -eq $null) {
     Add-PSSnapin VMware.VimAutomation.Core      }

## Unmap can take hour+ per data store on first run, remove timeout ###########
###############################################################################
Set-PowerCLIConfiguration -WebOperationTimeoutSeconds -1 -Scope Session -Confirm:$false

## Ignore Certificates Warning ################################################
###############################################################################
Set-PowerCLIConfiguration -InvalidCertificateAction Ignore -Scope Session -Confirm:$false

## Connect to vCenter Server ##################################################
# Prompt user for vCenter creds every time unless creds are stored using:
# New-VICredentialStoreItem -Host $VIServer -User "AD\user" -Password 'pass'
###############################################################################
$VC = Connect-VIServer $VCServer
Write-verbose "Connected to '$($VC.Name):$($VC.port)' as '$($VC.User)'"

## Connect to first ESXi host in list to run unmap ESXCLI #####################
###############################################################################
$ESXiHost = Get-VMHost |Select-Object -first 1
$ESXCLI = Get-EsxCli -VMHost $ESXiHost
Write-Verbose "Using ESXi host '($ESXiHost)' for CLI"


## Establish structure to store CSV data ######################################
# Try to open a CSV file, if it doesn't exist a new one will be created.
###############################################################################
try {
    $report = @( Import-Csv $output_file )
    }
catch {
    $report = @()
    }

## CSV Collect Data ###########################################################
# Function to collect datastore usage information to be stored in CSV
###############################################################################
function get_datastore_usage {
    Write-Verbose "[ $($dsv.Name) ] - Gathering statistics..."
    $row = "" |select TIMESTAMP, DATASTORE, CAPACITY_GB, FREE_GB, UNCOMMITED_GB
    $row.TIMESTAMP = $(((get-date).ToUniversalTime()).ToString("yyyyMMddThhmmssZ"))
    $row.DATASTORE = $ds.Name
    $row.CAPACITY_GB = [int]($ds.CapacityGB)
    $row.FREE_GB = [int]($ds.FreeSpaceGB)
    $row.UNCOMMITED_GB = [int]($dsv.Summary.Uncommitted / (1024 * 1024 * 1024))
    return $row
    }

## Unmap ######################################################################
# unmap creates a maximum of 200 (changable) 1MB files at a time to 100%.
###############################################################################
function reclaim_datastore_used_space {
    Write-Verbose "[ $($dsv.Name) ] - Running unmap, can take 30+ minutes"
    try {
        $RETVAL = $ESXCLI.storage.vmfs.unmap(200, $ds.Name, $null)
        }
    catch [VMware.VimAutomation.Sdk.Types.V1.ErrorHandling.VimException.ViError]{
        Write-Verbose $_.Exception.Message -foregroundcolor magenta
        }
    }

## Loop through datastores ####################################################
# Loops through all datastores seen by vCenter.  If the datastore is accessible
# and capable of thinprovisioning: Gathers datastore usage data, runs unmap
###############################################################################
foreach ($ds in Get-Datastore) {
    $dsv = $ds |Get-View
    if ($dsv.Summary.accessible -and $dsv.Capability.PerFileThinProvisioningSupported) {
        Write-Verbose "[ $($dsv.Name) ] - Refreshing Datastore Data..."
        $dsv.RefreshDatastore()
        $dsv.RefreshDatastoreStorageInfo()
        $report += get_datastore_usage
        reclaim_datastore_used_space
        }
    }


## Write CSV data to file #####################################################
###############################################################################
$report |Export-Csv $output_file -NoTypeInformation

## Open CSV file using Notepad ################################################
###############################################################################
Start-Process notepad -ArgumentList $output_file

## Properly disconnect from vCenter Server ####################################
###############################################################################
Disconnect-VIServer $VC -Confirm:$false

Note: The unmap command continues to run in the background, the blocks can be seen being unmapped in the ESXi Host hostd.log:

Unmap:  Async Unmapped 200 blocks from volume ...