Jobs fail on PS5 env - switching to Integrated env will run successfully

Hello,

Ever since updating to 2.4.0, I have been noticing a lot more jobs failing with the following:

# This job produced no output

If I try running them manually with the PS 5 env, it will fail. If I switch to the integrated env, it will go through just fine. Curious what I am missing?

@adam - Any thoughts?

If this is fixed in a later update, our enterprise license just expired and waiting to see if I can get them to renew it. I know the product will still work, but I believe we cannot install any updates.

Product: PowerShell Universal
Version: 2.4.0

I would check the log (C:\ProgramData\PowerSHellUniversal) to see why they are failing. I’d have to look through the changelog to see if there were any changes related to v5 between 2.4 and 2.5.4 but there is a chance something was fixed.

1 Like

Hey @adam

I found this in the log entry:

2021-11-21 00:01:05.829 -05:00 [DBG] Starting C:\Windows\System32\WindowsPowerShell\v1.0\powershell.exe with command line  -NoProfile -Command "& { [System.Reflection.Assembly]::LoadFrom('C:\Program Files (x86)\Universal\Host\host.dll') | Out-Null; [UniversalHost.AgentService]::StartJob(57152, 4660, $False, 52072) }"
2021-11-21 00:01:05.829 -05:00 [INF] Starting job using Process.
2021-11-21 00:01:05.840 -05:00 [DBG] Agent Output: 
2021-11-21 00:01:05.905 -05:00 [DBG] Agent Output: 
2021-11-21 00:01:10.601 -05:00 [INF] Error executing job 816126: Did not receive port from client process.    at UniversalAutomation.Services.GrpcExecutionService.ExecuteScript(Job job, ExecutionEnvironment environment, executeScriptRequest request, ExecutionCallback executionCallback) in D:\a\universal\universal\src\UniversalAutomation\Services\Automation\GrpcExecutionService.cs:line 80
   at UniversalAutomation.ExecutionService.ExecutePowerShell(Script script, IEnumerable`1 parameters, Job job, Schedule schedule, ExecutionCallback callback) in D:\a\universal\universal\src\UniversalAutomation\Services\Automation\ExecutionService.cs:line 617
   at UniversalAutomation.ExecutionService.TryExecute(Job job, Schedule schedule) in D:\a\universal\universal\src\UniversalAutomation\Services\Automation\ExecutionService.cs:line 324
   at UniversalAutomation.ExecutionService.Execute(Job job, Schedule schedule) in D:\a\universal\universal\src\UniversalAutomation\Services\Automation\ExecutionService.cs:line 244 System.Exception
2021-11-21 00:01:10.773 -05:00 [INF] Error executing job 816128: Did not receive port from client process.    at UniversalAutomation.Services.GrpcExecutionService.ExecuteScript(Job job, ExecutionEnvironment environment, executeScriptRequest request, ExecutionCallback executionCallback) in D:\a\universal\universal\src\UniversalAutomation\Services\Automation\GrpcExecutionService.cs:line 80
   at UniversalAutomation.ExecutionService.ExecutePowerShell(Script script, IEnumerable`1 parameters, Job job, Schedule schedule, ExecutionCallback callback) in D:\a\universal\universal\src\UniversalAutomation\Services\Automation\ExecutionService.cs:line 617
   at UniversalAutomation.ExecutionService.TryExecute(Job job, Schedule schedule) in D:\a\universal\universal\src\UniversalAutomation\Services\Automation\ExecutionService.cs:line 324
   at UniversalAutomation.ExecutionService.Execute(Job job, Schedule schedule) in D:\a\universal\universal\src\UniversalAutomation\Services\Automation\ExecutionService.cs:line 244 System.Exception
2021-11-21 00:01:10.851 -05:00 [INF] Error executing job 816127: Did not receive port from client process.    at UniversalAutomation.Services.GrpcExecutionService.ExecuteScript(Job job, ExecutionEnvironment environment, executeScriptRequest request, ExecutionCallback executionCallback) in D:\a\universal\universal\src\UniversalAutomation\Services\Automation\GrpcExecutionService.cs:line 80
   at UniversalAutomation.ExecutionService.ExecutePowerShell(Script script, IEnumerable`1 parameters, Job job, Schedule schedule, ExecutionCallback callback) in D:\a\universal\universal\src\UniversalAutomation\Services\Automation\ExecutionService.cs:line 617
   at UniversalAutomation.ExecutionService.TryExecute(Job job, Schedule schedule) in D:\a\universal\universal\src\UniversalAutomation\Services\Automation\ExecutionService.cs:line 324
   at UniversalAutomation.ExecutionService.Execute(Job job, Schedule schedule) in D:\a\universal\universal\src\UniversalAutomation\Services\Automation\ExecutionService.cs:line 244 System.Exception
2021-11-21 00:01:22.157 -05:00 [DBG] Element POST - id = bannerStatus
2021-11-21 00:01:30.845 -05:00 [DBG] Element POST - id = 66999a0f-3050-4f09-ad34-201be93ed099

These scripts have been in place since we updated to 2.0.X and ran fine up until we updated to 2.4.0

I appreciate you taking a look!

One thing I would suggest would be to run this in a terminal and see if any errors are shown. Sometimes, there can be assembly load errors that prevent jobs from running. Those are certainly resolved in later versions since I haven’t seen any issue running jobs in WinPS in recent versions. Give it a try and let me know what the output is.

powershell  -NoProfile -Command "& { [System.Reflection.Assembly]::LoadFrom('C:\Program Files (x86)\Universal\Host\host.dll') | Out-Null; [UniversalHost.AgentService]::StartJob(57152, 4660, $False, 52072) }"
1 Like

Hey @adam

I ran this from the desktop and it produced no output:

Microsoft Windows [Version 10.0.17763.2237]
(c) 2018 Microsoft Corporation. All rights reserved.

N:\>powershell  -NoProfile -Command "& { [System.Reflection.Assembly]::LoadFrom('C:\Program Files (x86)\Universal\Host\host.dll') | Out-Null; [UniversalHost.AgentService]::StartJob(57152, 4660, $False, 52072) }"

N:\>

Ok. It looks like it’s loading the assemblies properly. The next thing I would try would be to increase the job time out. In appsettings.json, you can do this by setting JobHandshakeTimeout

  "UniversalAutomation": {
    "JobHandshakeTimeout": 5,
    "JobDebugging": false,
    "ContinueJobOnServerStop": false
  },

JobDebugging also might be also be helpful as it will write additional logs about the startup process for jobs. It writes them to the TEMP directory as PSU.*.txt

1 Like

Hey @adam,

So I changed the timeout to 15 and set JobDebugging to true. I restarted the service, that seemed to fix everything. However, something funky is still up. 1) I do not see any logs being created in %TEMP% and 2) I watched the schedule a job showed up saying it was manually triggered by me, but I did not trigger anything and it keeps coming back every four minutes.

I don’t think I am logged in somewhere else, is there a way to log out or see who is logged in currently?

Here is what I grabbed from hangfire:

// Job ID: 8bff22eb-a2e8-44bb-bf31-676b7a644f85
using UniversalAutomation;

var executionService = Activate<ExecutionService>();
await executionService.Execute(
    FromJson<Job>("{\"Id\":820353,\"CreatedTime\":\"2021-11-23T17:05:50.5878388Z\",\"ScriptFullPath\":\"FTERedefine.ps1\",\"AppToken\":{\"Id\":256811,\"Token\":\"aTOKENHERE\",\"Identity\":{\"Id\":1},\"Role\":\"Execute\",\"Created\":\"2021-07-15T18:35:45.362-04:00\",\"Expiration\":\"2022-07-15T18:35:00-04:00\",\"CreatedBy\":{\"Id\":1}},\"Identity\":{\"Id\":1,\"Name\":\"myUserName\",\"RoleName\":\"Administrator\"},\"Environment\":\"Integrated\",\"Computer\":{\"Id\":1,\"Name\":\"SERVER\"}}"),
    null);

This is what showed up in the schedule:

820356	FTERedefine.ps1	success	run manually by myUsername in the Integrated environment	
4 minutes ago
31s

Edit: I realize that I have an AppToken checked out that techs can kick off a script from a dashboard, however, no one was in the dashboard. Is it possible these were queued up? The script requires parameters and parameters were passed to it. Also, we were unable to revoke any AppTokens from the GUI.

The TEMP dir might depend on which user is running the PSU service. We use [IO.Path]::GetTempPath() to look up the temp path.

As for the jobs started as you, you may want to look in the recurring job tab in hangfire to see what is listed there. What kind of schedule is this? Continuous or standard CRON?