Use runspaces instead of PS job for plugin commands

PoshBot/Classes/Bot.ps1

@@ -481,7 +481,7 @@ class Bot : BaseLogger {
                         $this.LogInfo([LogSeverity]::Error, "Errors encountered running command [$($cmdExecContext.FullyQualifiedCommandName)]", $cmdExecContext.Result.Errors)
                     }
                 } else {
-                    $this.LogVerbose('Command execution result', $cmdExecContext.Result)
+                    $this.LogVerbose('Command execution result', $cmdExecContext.Result.Output)
                     foreach ($resultOutput in $cmdExecContext.Result.Output) {
                         if ($null -ne $resultOutput) {
                             if ($this._IsCustomResponse($resultOutput)) {

PoshBot/Classes/Command.ps1

@@ -125,15 +125,8 @@ class Command : BaseLogger {
         $options.PositionalParameters = $ParsedCommand.PositionalParameters
 
         if ($InvokeAsJob) {
-            $this.LogDebug("Executing command [$($this.ModuleQualifiedCommand)] as job")
-            $fdt = [guid]::NewGuid().ToString().Replace('-', '')
-            $jobName = "$($this.Name)_$fdt"
-            $jobParams = @{
-                Name = $jobName
-                ScriptBlock = $outer
-                ArgumentList = $options
-            }
-            return (Start-Job @jobParams)
+            $this.LogDebug("Executing command [$($this.ModuleQualifiedCommand)] as runspace job")
+            return [RunspaceJob]::new("$($this.Name)_$(Get-Date -Format FileDateTimeUniversal)", $outer, $options)
         } else {
             $this.LogDebug("Executing command [$($this.ModuleQualifiedCommand)] in current PS session")
             $errors = $null

PoshBot/Classes/CommandExecutionContext.ps1

@@ -11,7 +11,7 @@ class CommandExecutionContext {
     [bool]$IsJob
     [datetime]$Started
     [datetime]$Ended
-    [object]$Job
+    [RunspaceJob]$RunspaceJob
     [ApprovalState]$ApprovalState = [ApprovalState]::AutoApproved
     [Approver]$Approver = [Approver]::new()
     [Response]$Response = [Response]::new()

PoshBot/Classes/CommandExecutor.ps1

@@ -103,8 +103,8 @@ class CommandExecutor : BaseLogger {
 
                     # Kick off job and add to job tracker
                     $Context.IsJob = $true
-                    $Context.Job = $Context.Command.Invoke($Context.ParsedCommand, $true,$this._bot.Backend.GetType().Name)
-                    $this.LogDebug("Command [$($Context.FullyQualifiedCommandName)] executing in job [$($Context.Job.Id)]")
+                    $Context.RunspaceJob = $Context.Command.Invoke($Context.ParsedCommand, $true, $this._bot.Backend.GetType().Name)
+                    $this.LogDebug("Command [$($Context.FullyQualifiedCommandName)] executing in runspace job [$($Context.RunspaceJob.Id)]")
                     $Context.Complete = $false
                 } else {
                     # Run command in current session and get results
@@ -169,26 +169,12 @@ class CommandExecutor : BaseLogger {
             # Builtin commands are NOT executed as jobs so their output
             # was already recorded in the [Result] property in the ExecuteCommand() method
             if ($context.IsJob) {
+                $context.RunspaceJob.EndJob([ref]$context.Result)
 
-                # Determine if job had any terminating errors and capture error stream
-                if ($context.Job.State -in @('Completed', 'Failed')) {
-                    $context.Result.Errors  = $context.Job.ChildJobs[0].Error.ReadAll()
-                    $context.Result.Success = ($context.Result.Errors.Count -eq 0)
-                }
                 $this.LogVerbose("Command [$($context.FullyQualifiedCommandName)] with job ID [$($context.Id)] completed with result: [$($context.Result.Success)]")
 
                 $context.Complete = $true
                 $context.Ended = [datetime]::UtcNow
-
-                # Capture all the streams
-                $context.Result.Streams.Error       = $context.Result.Errors
-                $context.Result.Streams.Information = $context.Job.ChildJobs[0].Information.ReadAll()
-                $context.Result.Streams.Verbose     = $context.Job.ChildJobs[0].Verbose.ReadAll()
-                $context.Result.Streams.Warning     = $context.Job.ChildJobs[0].Warning.ReadAll()
-                $context.Result.Output              = $context.Job.ChildJobs[0].Output.ReadAll()
-
-                # Clean up the job
-                Remove-Job -Job $context.Job
             }
 
             # Send a success, warning, or fail reaction
@@ -340,7 +326,7 @@ class CommandExecutor : BaseLogger {
     hidden [CommandExecutionContext[]]_GetCompletedContexts() {
         $jobs = $this._jobTracker.GetEnumerator().Where({
             ($_.Value.Complete -eq $true) -or
-            ($_.Value.IsJob -and (($_.Value.Job.State -eq 'Completed') -or ($_.Value.Job.State -eq 'Failed')))
+            ($_.Value.IsJob -and $_.Value.RunspaceJob.Handle.IsCompleted)
         }) | Select-Object -ExpandProperty Value
         return $jobs
     }

PoshBot/Classes/LogMessage.ps1

@@ -43,7 +43,7 @@ class LogMessage {
                 # Summarize exceptions so they can be serialized to json correctly
 
                 # Don't try to serialize jobs
-                if ($item.GetType().BaseType.ToString() -eq 'System.Management.Automation.Job') {
+                if ($item.GetType().BaseType.ToString() -eq 'RunspaceJob') {
                     continue
                 }
 

PoshBot/Classes/RunspaceJob.ps1

@@ -0,0 +1,45 @@
+class RunspaceJob {
+    [System.Management.Automation.PowerShell]$PowerShell
+    [System.IAsyncResult]$Handle
+
+    RunspaceJob([string]$Name, [scriptblock]$Code, [hashtable]$Options) {
+        $this.PowerShell = [PowerShell]::Create()
+
+        # For some reason have to explicitly create a new runspace
+        # Otherwise, after PowerShell.Dispose() gets called weird errors start happening e.g:
+        #   Unable to find type [System.Net.Http.HttpClient]
+        #   Object reference not set to an instance of an object.
+        # Dispose() affects the current session???
+        # Even calling Create() with [System.Management.Automation.RunspaceMode]::NewRunspace didn't seem to work
+        $this.PowerShell.Runspace = [runspacefactory]::CreateRunspace()
+        $this.PowerShell.Runspace.Name = $Name
+        $this.PowerShell.Runspace.Open()
+
+        $this | Add-Member -Name Id -Force -MemberType ScriptProperty -Value {
+            return $this.PowerShell.Runspace.Id
+        }
+
+        $this.Handle = $this.PowerShell.AddScript($Code).AddParameter('Options', $Options).BeginInvoke()
+    }
+
+    [void]EndJob( [ref]$CommandResult ) {
+        $CommandResult.Value.Errors              = $this.PowerShell.Streams.Error.ReadAll()
+        $CommandResult.Value.Streams.Error       = $CommandResult.Value.Errors
+        $CommandResult.Value.Streams.Information = $this.PowerShell.Streams.Information.ReadAll()
+        $CommandResult.Value.Streams.Verbose     = $this.PowerShell.Streams.Verbose.ReadAll()
+        $CommandResult.Value.Streams.Warning     = $this.PowerShell.Streams.Warning.ReadAll()
+
+        try {
+            $CommandResult.Value.Output  = $this.PowerShell.EndInvoke($this.Handle)
+        } catch {
+            # Unwrap the exception otherwise it will blame EndInvoke for the exception
+            #   e.g. Exception calling "EndInvoke" with "1" argument(s): "Attempted to divide by zero."
+            $CommandResult.Value.Errors = $_.Exception.InnerException.ErrorRecord
+        } finally {
+            $this.PowerShell.Dispose()
+        }
+
+        # # Job is deemed successful if no items in error stream
+        $CommandResult.Value.Success = $CommandResult.Value.Errors.Count -eq 0
+    }
+}

psakeFile.ps1

@@ -170,6 +170,7 @@ task Compile -depends Clean {
         'Trigger'
         'StorageProvider'
         'RoleManager'
+        'RunspaceJob'
         'Command'
         'CommandHistory'
         'Plugin'