Automation Error: Did not receive port from client process

PowerShell Universal
1

Hey Folks

In our lab, during a load test with JMeter against Powershell Universal Automation, I noticed that a few jobs get not completed. They are reside in error state: Error executing job: Did not receive port from client process.
In this example I used 8 simultaneous connections and repeated 8 times, resulting in 64 Jobs

image

On the task manager the failed “jobs” are shown like this. The processes never exites.

image
image1833×61 11.1 KB

The log entries:

2020-08-19T11:36:10.4079941+02:00 0HM241BSHMID4:00000002 [INF] Request starting
HTTP/1.1 GET http://localhost/api/v1/Script/9 (ca22a1cb)
2020-08-19T11:36:10.4677194+02:00 0HM241BSHMIDK:00000002 [INF] Successfully validated the token. (60169667)
2020-08-19T11:36:10.4677896+02:00 0HM241BSHMIDK:00000002 [INF] Authorization was successful. (0d575a54)
2020-08-19T11:36:10.4678175+02:00 0HM241BSHMIDK:00000002 [INF] Executing endpoint ‘“UniversalAutomation.ScriptController.Get (UniversalAutomation)”’ (500cc934)
2020-08-19T11:36:10.4678745+02:00 0HM241BSHMIDK:00000002 [INF] Route matched with “{action = "Get", controller = "Script"}”. Executing controller action with signature “UniversalAutomation.Script Get(Int64)” on controller “UniversalAutomation.ScriptController” (“UniversalAutomation”). (122b2fdf)
2020-08-19T11:36:10.4686591+02:00 0HM241BSHMIDK:00000002 [INF] Executing ObjectResult, writing value of type ‘“UniversalAutomation.Script”’. (8a1b66c8)
2020-08-19T11:36:10.4688902+02:00 0HM241BSHMIDK:00000002 [INF] Executed action “UniversalAutomation.ScriptController.Get (UniversalAutomation)” in 0.9861ms (afa2e885)
2020-08-19T11:36:10.4689166+02:00 0HM241BSHMIDK:00000002 [INF] Executed endpoint ‘“UniversalAutomation.ScriptController.Get (UniversalAutomation)”’ (99874f2b)
2020-08-19T11:36:10.4690075+02:00 0HM241BSHMIDK:00000002 [INF] Request finished in 115.5514ms 200 application/json; charset=utf-8 (791a596a)
2020-08-19T11:36:10.4691131+02:00 0HM241BSHMIDN:00000001 [INF] Request starting HTTP/1.1 GET http://localhost/api/v1/Job/18164 (ca22a1cb)
2020-08-19T11:36:10.5234067+02:00 0HM241BSHMID4:00000002 [INF] Successfully validated the token. (60169667)
2020-08-19T11:36:10.5234713+02:00 0HM241BSHMID4:00000002 [INF] Authorization was successful. (0d575a54)
2020-08-19T11:36:10.5234980+02:00 0HM241BSHMID4:00000002 [INF] Executing endpoint ‘“UniversalAutomation.ScriptController.Get (UniversalAutomation)”’ (500cc934)
2020-08-19T11:36:10.5235560+02:00 0HM241BSHMID4:00000002 [INF] Route matched with “{action = "Get", controller = "Script"}”. Executing controller action with signature “UniversalAutomation.Script Get(Int64)” on controller “UniversalAutomation.ScriptController” (“UniversalAutomation”). (122b2fdf)
2020-08-19T11:36:10.5243438+02:00 0HM241BSHMID4:00000002 [INF] Executing ObjectResult, writing value of type ‘“UniversalAutomation.Script”’. (8a1b66c8)
2020-08-19T11:36:10.5245674+02:00 0HM241BSHMID4:00000002 [INF] Executed action “UniversalAutomation.ScriptController.Get (UniversalAutomation)” in 0.9867ms (afa2e885)
2020-08-19T11:36:10.5245908+02:00 0HM241BSHMID4:00000002 [INF] Executed endpoint ‘“UniversalAutomation.ScriptController.Get (UniversalAutomation)”’ (99874f2b)
2020-08-19T11:36:10.5246799+02:00 0HM241BSHMID4:00000002 [INF] Request finished in 116.6923ms 200 application/json; charset=utf-8 (791a596a)
2020-08-19T11:36:10.5247823+02:00 0HM241BSHMID7:00000002 [INF] Request starting HTTP/1.1 GET http://localhost/api/v1/Script/9 (ca22a1cb)
2020-08-19T11:36:10.5483307+02:00 [INF] Error executing job 18179: Did not receive port from client process. at UniversalAutomation.ExecutionService.ExecutePowerShell(Script script, IEnumerable`1 parameters, Job job, Schedule schedule, Int32 port, ExecutionCallback callback) in D:\a\universal\universal\src\UniversalAutomation\Services\ExecutionService.cs:line 369
at UniversalAutomation.ExecutionService.TryExecute(Job job, Schedule schedule) in D:\a\universal\universal\src\UniversalAutomation\Services\ExecutionService.cs:line 273
at UniversalAutomation.ExecutionService.Execute(Job job, Schedule schedule) in D:\a\universal\universal\src\UniversalAutomation\Services\ExecutionService.cs:line 156 System.Exception (7230dcc0)
2020-08-19T11:36:10.5496258+02:00 0HM241BSHMIDJ:00000002 [INF] Request starting HTTP/1.1 GET http://localhost/api/v1/Script/9 (ca22a1cb)

Have you the same behavior experienced, or is this a configuration issue on my side?
I tested this on 1.3.0 and 1.3.1 nightly. On IIS the errors are reproducable.

2

Hey @viscop !

Have you taken care of the warning stated in the following part of the setup on IIS ? https://docs.ironmansoftware.com/config/hosting-iis#3-1-choosing-an-app-pool-identity

IIS Limitations with Universal Automation

  • App Service configured as Local System - Scripts will execute as the System Account by default and a Run as Accounts CAN be specified when executing a Script in Universal Automation

  • App Service configured as a Service Account - Scripts can ONLY be executed with the Service Account and a ****** Run as Account CANNOT** be specified when executing scripts

usually the error you’re refering to is linked to this configuration.

3

Hi @Speegel

Thanks for reply.
Yes I did.
The configuration should be o.k. Scripts are running as Local System.

Basicly Powershell Universal is hosted as a Windows Service, I did some Tests with IIS, the same behavior as with the Windows Service.