#Runspaces and Real-Time Output Streams

16 messages · Page 1 of 1 (latest)

sly nymph
#

Hey guys,

I am creating a PowerShell runspace to execute a "handler" script like this:

$InitialSessionState = [System.Management.Automation.Runspaces.InitialSessionState]::CreateDefault()
$InitialSessionState.LanguageMode = [System.Management.Automation.PSLanguageMode]::ConstrainedLanguage
$Runspace = [System.Management.Automation.Runspaces.RunspaceFactory]::CreateRunspace($InitialSessionState)
$Runspace.Open() | Out-Null

$HandlerPS = [System.Management.Automation.PowerShell]::Create()
$HandlerPS.Runspace = $Runspace
$HandlerScriptContent = Get-Content -Path $Path -Raw
$HandlerPS.AddScript($HandlerScriptContent) | Out-Null
$HandlerPS.Invoke() | Out-Null

$HandlerPS.Dispose() | Out-Null
$Runspace.Dispose() | Out-Null

This works perfectly fine and the handlers execute properly. My problem is, I'm running this in an Azure Function which records anything from the output stream to application insights for logging purposes.

Any time a Write-Information or Write-Warning etc is invoked, the output is not recorded from inside the handler (runspace). I know i can access this after execution by accessing the $HandlerPS.Streams , but is there a way to make the logging work in realtime (allowing the runspace output to be captured by the parent runspace/host).

I also tried creating the runspace like [System.Management.Automation.Runspaces.RunspaceFactory]::CreateRunspace($Host, $InitialSessionState) which had even weirder results because if i use this then logging doesnt work at all even for the main runspace once the handler runspace is invoked.

Any help or tips appreciated 🙂

slim laurel
#

you would want to BeginInvoke to run in the background, and potentially subscribe to DataAdded events on each of the streams you're interested in.

sly nymph
slim laurel
sly nymph
#

@slim laurel Is this what you meant by subscribing to the streams? I've done it like this but not sure I've done it correctly, it isn't working for me:

$HandlerPS = [System.Management.Automation.PowerShell]::Create()
$HandlerPS.Runspace = $Runspace

$Events = @()
$StreamHandlers = @{
    'Error'       = { Write-Error -Exception $Event.Sender[$Event.SourceEventArgs.Index].Exception }
    'Warning'     = { Write-Warning -Message $Event.Sender[$Event.SourceEventArgs.Index].Message }
    'Verbose'     = { Write-Verbose -Message $Event.Sender[$Event.SourceEventArgs.Index].Message }
    'Debug'       = { Write-Debug -Message $Event.Sender[$Event.SourceEventArgs.Index].Message }
    'Information' = { Write-Information -MessageData $Event.Sender[$Event.SourceEventArgs.Index].MessageData -InformationAction Continue }
}
foreach ($Stream in $HandlerPS.Streams.PSObject.Properties) {
    if ($StreamHandlers.ContainsKey($Stream.Name)) {
        $Events += Register-ObjectEvent -InputObject $HandlerPS.Streams.($Stream.Name) -EventName DataAdded -Action $StreamHandlers[$Stream.Name]
    }
}

$HandlerPS.AddScript($HandlerScriptContent) | Out-Null
$HandlerPSAsync = $HandlerPS.BeginInvoke()

[datetime]$StartTime = Get-Date
[datetime]$Timeout = $StartTime.AddSeconds($Timeout)
while ($true) {
    if ($HandlerPSAsync.IsCompleted) {
        $HandlerPS.EndInvoke($HandlerPSAsync) | Out-Null
        break
    }
    else {
        if ((Get-Date) -ge $Timeout) {
            $HandlerPS.Stop() | Out-Null
            throw "Handler script execution timed out after [$($Timeout)] seconds."
        }
        Start-Sleep -Milliseconds 100
    }
}
slim laurel
#

I'd probably use a Get-Event | Wait-Event to ensure all of those run in the foreground. And don't forget that Verbose and Debug show nothing by default unless you either have the explicit parameters or have set the preference variables.

sly nymph
#

Would i run that before $HandlerPS.BeginInvoke() or afterwards?

slim laurel
#

After

sly nymph
#

Hmm still didn't work lol, this is going to be a long day

manic flint
#

Do you need a runspace, can you jusy use the current one and set CLM?

sly nymph
manic flint
#

And do you just care about streaming the output or also the other streams?

sly nymph
sly nymph
# 
[datetime]$StartTime = [datetime]::Now
[datetime]$Timeout = $StartTime.AddSeconds($Timeout) # -- Set a timeout for the handler script execution
while ($true) {
    if ($HandlerPSAsync.IsCompleted) {
        # -- Give the output stream event subscribers a chance to process any remaining events
        $EventProcessingStart = [datetime]::Now
        while ($true) {
            $PendingEvents = Get-Event -ErrorAction SilentlyContinue

            # -- Exit loop if no more events or we've waited too long
            if (-not $PendingEvents -or $PendingEvents.Count -eq 0) {
                break
            }
            if (([datetime]::Now) -gt $EventProcessingStart.AddSeconds(5)) {
                Write-Warning 'Timed out whilst waiting for handler output stream events to process. Logging may be incomplete!'
                break
            }

            # -- Process events by removing them from the queue
            foreach ($Event in $PendingEvents) {
                Remove-Event -EventIdentifier $Event.EventIdentifier -ErrorAction SilentlyContinue
            }

            # -- Sleep to allow for event processing
            [System.Threading.Thread]::Sleep(50)
        }

        # -- End the handler script invocation
        $HandlerPS.EndInvoke($HandlerPSAsync) | Out-Null
        break
    }
    else {
        # -- Check if the timeout has been reached
        if (([datetime]::Now) -ge $Timeout) {
            $HandlerPS.Stop() | Out-Null
            throw "Handler script execution timed out after [$($Timeout)] seconds."
        }

        # -- Sleep for 100ms to avoid busy waiting (Avoiding Start-Sleep here for performance reasons)
        [System.Threading.Thread]::Sleep(100)
    }
}

Looks like i fixed it by allowing a fraction of a second for the events to be processed and removing them from the queue.

tidal fox
sly nymph
# tidal fox `DataAdding` instead of `DataAdded` is much easier to handle

I think you're right, I've updated it to this:

$StreamHandlers = @{
    'Error'       = { Write-Error -Exception $Event.SourceEventArgs.ItemAdded.Exception }
    'Warning'     = { Write-Warning -Message $Event.SourceEventArgs.ItemAdded.Message }
    'Verbose'     = { Write-Verbose -Message $Event.SourceEventArgs.ItemAdded.Message -Verbose }
    'Debug'       = { Write-Debug -Message $Event.SourceEventArgs.ItemAdded.Message -Debug }
    'Information' = { Write-Information -MessageData $Event.SourceEventArgs.ItemAdded.MessageData }
}
foreach ($Stream in $HandlerPS.Streams.PSObject.Properties) {
    if ($StreamHandlers.ContainsKey($Stream.Name)) {
        $EventSubscribers += Register-ObjectEvent -InputObject $HandlerPS.Streams.($Stream.Name) -EventName DataAdding -Action $StreamHandlers[$Stream.Name]
    }
}