App Tokens don't seem to work in PSU 5.0.5

While troubleshooting why VS Code could no longer connect to PSU after upgrading from 4.3.4 to 5.0.5, due to what it was saying was an app token issue (Error 500), I deleted the existing app token and generated a new token.

Side issue: the little notification box that shows you what your new app token is doesn’t show any longer, so I had to disable Enhanced App Token Security in order to be able to use the Copy button next to the token.

Attempting to use this new token still resulted in VS Code saying it couldn’t connect, and gave an Error 500.

Switching over to the Swagger page, I entered the token at the top to authenticate, and then tried using some of the APIs to see if I could query anything. All of these resulted in Error 500’s as well.

This seems to confirm that App Tokens are not being stored in the DB properly, or something else is happening. Opening up the DB, with Enhanced App Token Security disabled, I can see the generated token, so it’s not an issue of storing the token in the DB. I’m not sure what’s going on yet.

Edit: Digging some more, and doing some more testing with Postman, I see that even with the following in my appsettings.json file, gRPC is still throwing up error 500 responses.

 "Api": {
	  "SecurityModel": "Permissive"
  },

In Postman, I get:

Cannot retrieve the dynamic parameters for the cmdlet. Status(StatusCode="Internal", Detail="Error starting gRPC call. HttpRequestException: The SSL connection could not be established, see inner exception. AuthenticationException: The remote certificate was rejected by the provided RemoteCertificateValidationCallback.", DebugException="System.Net.Http.HttpRequestException: The SSL connection could not be established, see inner exception.")

If I add -TrustCertificate to the end of my Endpoint’s Invoke-PSUScript line, the error changes to:

Cannot retrieve the dynamic parameters for the cmdlet. Status(StatusCode="Unknown", Detail="Bad gRPC response. HTTP status code: 500")
Product: PowerShell Universal
Version: 5.0.5

Can you check the system logs? There is some configuration setting\data state that is very unhappy in this environment. Hopefully, the 500 error will have a good exception and stack trace.

We have a couple hundred integration tests that use app tokens and I can connect VS Code in my 5.0.5 environment so it seems to work out of the box but may be an upgrade problem that I’m unclear on.

I relaunched the service to generate a fresh log. I removed a few things that were privacy concerns, but here is what it has in it:

2024-09-03 12:44:50.894 -04:00 [INF] Starting PowerShell Universal...
2024-09-03 12:44:51.065 -04:00 [INF] PowerShell Universal Version: 5.0.5
2024-09-03 12:44:51.067 -04:00 [INF] OS Version: Microsoft Windows NT 10.0.20348.0
2024-09-03 12:44:51.067 -04:00 [INF] OS Architecture: x64
2024-09-03 12:44:51.067 -04:00 [INF] Process Architecture: x64
2024-09-03 12:44:51.067 -04:00 [INF] Node Name: CLISRV-PSUNI1
2024-09-03 12:44:51.067 -04:00 [INF] Running startup complete.
2024-09-03 12:44:51.084 -04:00 [INF] Starting PowerShell Universal...
2024-09-03 12:44:51.092 -04:00 [INF] Starting management service...
2024-09-03 12:44:51.203 -04:00 [INF] Loading app tokens...
2024-09-03 12:44:51.258 -04:00 [INF] Initializing database...
2024-09-03 12:44:51.300 -04:00 [INF] RPC services being provided by UniversalAutomation.IPublicSecretManagerService: 1
2024-09-03 12:44:51.310 -04:00 [INF] RPC services being provided by PowerShellUniversal.IdentityClient: 6
2024-09-03 12:44:51.322 -04:00 [INF] RPC services being provided by PowerShellUniversal.JobDataService: 11
2024-09-03 12:44:51.326 -04:00 [WRN] Type cannot be serialized; ignoring: PowerShellUniversal.AuthenticationMethod
2024-09-03 12:44:51.326 -04:00 [WRN] Signature not recognized for PowerShellUniversal.IPublicClient.NewAuthenticationMethod; method will not be bound
2024-09-03 12:44:51.328 -04:00 [WRN] Type cannot be serialized; ignoring: PowerShellUniversal.Translation
2024-09-03 12:44:51.328 -04:00 [WRN] Signature not recognized for PowerShellUniversal.IPublicClient.NewTranslation; method will not be bound
2024-09-03 12:44:51.330 -04:00 [WRN] Signature not recognized for PowerShellUniversal.IPublicClient.SyncComponent; method will not be bound
2024-09-03 12:44:51.350 -04:00 [INF] RPC services being provided by PowerShellUniversal.PublicClient: 30
2024-09-03 12:44:51.355 -04:00 [INF] RPC services being provided by PowerShellUniversal.ComputerClient: 5
2024-09-03 12:44:51.360 -04:00 [INF] RPC services being provided by Universal.Server.Services.DashboardGrpcClient: 7
2024-09-03 12:44:51.361 -04:00 [WRN] Type cannot be serialized; ignoring: System.IDisposable
2024-09-03 12:44:51.361 -04:00 [WRN] Signature not recognized for PowerShellUniversal.IConfigurationSystemWatcher.Pause; method will not be bound
2024-09-03 12:44:51.361 -04:00 [WRN] Signature not recognized for PowerShellUniversal.IConfigurationSystemWatcher.CheckSum; method will not be bound
2024-09-03 12:44:51.362 -04:00 [INF] RPC services being provided by Universal.Server.Services.Configuration.ConfigurationSystemWatcher: 2
2024-09-03 12:44:51.367 -04:00 [INF] RPC services being provided by Universal.Server.Services.Configuration.PortalComponentService: 5
2024-09-03 12:44:51.371 -04:00 [INF] RPC services being provided by Universal.Server.Services.Configuration.PortalPageService: 5
2024-09-03 12:44:51.373 -04:00 [INF] RPC services being provided by Universal.Server.Services.Automation.JobInvokerService: 2
2024-09-03 12:44:51.378 -04:00 [INF] RPC services being provided by Universal.Server.Services.Authentication.AppTokenClient: 6
2024-09-03 12:44:51.382 -04:00 [INF] RPC services being provided by UniversalAutomation.Services.ComputerGroupService: 5
2024-09-03 12:44:51.387 -04:00 [INF] RPC services being provided by UniversalAutomation.Services.EndpointDocumentationService: 5
2024-09-03 12:44:51.391 -04:00 [INF] RPC services being provided by UniversalAutomation.Services.EndpointService: 5
2024-09-03 12:44:51.395 -04:00 [INF] RPC services being provided by UniversalAutomation.Services.EnvironmentConfigService: 5
2024-09-03 12:44:51.399 -04:00 [INF] RPC services being provided by UniversalAutomation.Services.EventHubService: 5
2024-09-03 12:44:51.403 -04:00 [INF] RPC services being provided by UniversalAutomation.Services.FolderService: 5
2024-09-03 12:44:51.408 -04:00 [INF] RPC services being provided by UniversalAutomation.Services.HealthCheckConfigService: 5
2024-09-03 12:44:51.412 -04:00 [INF] RPC services being provided by UniversalAutomation.Services.ModuleConfigService: 5
2024-09-03 12:44:51.417 -04:00 [INF] RPC services being provided by UniversalAutomation.Services.PublishedFolderCommand: 5
2024-09-03 12:44:51.422 -04:00 [INF] RPC services being provided by UniversalAutomation.Services.RoleService: 5
2024-09-03 12:44:51.426 -04:00 [INF] RPC services being provided by UniversalAutomation.Services.ScriptService: 5
2024-09-03 12:44:51.427 -04:00 [INF] Loading configuration files...
2024-09-03 12:44:51.430 -04:00 [INF] RPC services being provided by UniversalAutomation.Services.TagService: 5
2024-09-03 12:44:51.434 -04:00 [INF] RPC services being provided by UniversalAutomation.Services.TerminalService: 5
2024-09-03 12:44:51.438 -04:00 [INF] RPC services being provided by UniversalAutomation.Services.TriggerService: 5
2024-09-03 12:44:51.442 -04:00 [INF] RPC services being provided by UniversalAutomation.Services.VariableService: 5
2024-09-03 12:44:51.446 -04:00 [INF] RPC services being provided by PowerShellUniversal.IGitSettingsService: 4
2024-09-03 12:44:51.472 -04:00 [INF] RPC services being provided by UniversalAutomation.IPublicGitService: 3
2024-09-03 12:44:51.475 -04:00 [INF] RPC services being provided by UniversalAutomation.IPublicApiService: 1
2024-09-03 12:44:51.479 -04:00 [INF] RPC services being provided by UniversalAutomation.IPublicGitSyncService: 5
2024-09-03 12:44:51.481 -04:00 [INF] RPC services being provided by PowerShellUniversal.IBrandingService: 1
2024-09-03 12:44:51.540 -04:00 [WRN] HTTP/2 is not enabled for [::]:5000. The endpoint is configured to use HTTP/1.1 and HTTP/2, but TLS is not enabled. HTTP/2 requires TLS application protocol negotiation. Connections to this endpoint will use HTTP/1.1.
2024-09-03 12:44:51.549 -04:00 [INF] Now listening on: http://[::]:5000
2024-09-03 12:44:51.549 -04:00 [INF] Now listening on: https://[::]:443
2024-09-03 12:44:51.552 -04:00 [INF] Starting Hangfire Server using job storage: 'In-Memory Storage'
2024-09-03 12:44:51.554 -04:00 [INF] Using the following options for Hangfire Server:
    Worker count: 100
    Listening queues: 'default', 'clisrvpsuni1'
    Shutdown timeout: 00:00:00.5000000
    Schedule polling interval: 00:00:15
2024-09-03 12:44:51.557 -04:00 [INF] Application started. Hosting environment: Production; Content root path: C:\Program Files (x86)\Universal\
2024-09-03 12:44:51.560 -04:00 [INF] Server clisrv-psuni1:2280:6ab5c015 successfully announced in 0.559 ms
2024-09-03 12:44:51.561 -04:00 [INF] Server clisrv-psuni1:2280:6ab5c015 is starting the registered dispatchers: ServerWatchdog, ServerJobCancellationWatcher, Worker, DelayedJobScheduler, RecurringJobScheduler...
2024-09-03 12:44:51.569 -04:00 [INF] Server clisrv-psuni1:2280:6ab5c015 all the dispatchers started
2024-09-03 12:44:52.114 -04:00 [INF] Request starting HTTP/2 POST https://<redacted>/_blazor/negotiate?negotiateVersion=1 - null 0
2024-09-03 12:44:52.141 -04:00 [INF] CORS policy execution failed.
2024-09-03 12:44:52.141 -04:00 [INF] Request origin https://<redacted> does not have permission to access the resource.
2024-09-03 12:44:52.267 -04:00 [INF] Executing endpoint '/_blazor/negotiate'
2024-09-03 12:44:52.272 -04:00 [INF] Executed endpoint '/_blazor/negotiate'
2024-09-03 12:44:52.273 -04:00 [INF] Request finished HTTP/2 POST https://<redacted>/_blazor/negotiate?negotiateVersion=1 - 200 316 application/json 160.8967ms
2024-09-03 12:44:52.292 -04:00 [INF] Request starting HTTP/2 CONNECT https://<redacted>/_blazor?id=tD_U5qUTEm4VztnZkSs7PA - null null
2024-09-03 12:44:52.297 -04:00 [INF] CORS policy execution failed.
2024-09-03 12:44:52.297 -04:00 [INF] Request origin https://<redacted> does not have permission to access the resource.
2024-09-03 12:44:52.311 -04:00 [INF] Executing endpoint '/_blazor'
2024-09-03 12:44:52.937 -04:00 [INF] Executing endpoint '/_Host'
2024-09-03 12:44:52.943 -04:00 [INF] Route matched with {page = "/_Host", action = "", controller = ""}. Executing page /_Host
2024-09-03 12:44:52.944 -04:00 [INF] Antiforgery token validation failed. The required antiforgery cookie ".AspNetCore.Antiforgery.eMUepvB4I2Y" is not present.
Microsoft.AspNetCore.Antiforgery.AntiforgeryValidationException: The required antiforgery cookie ".AspNetCore.Antiforgery.eMUepvB4I2Y" is not present.
   at Microsoft.AspNetCore.Antiforgery.DefaultAntiforgery.ValidateRequestAsync(HttpContext httpContext)
   at Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.ValidateAntiforgeryTokenAuthorizationFilter.OnAuthorizationAsync(AuthorizationFilterContext context)
2024-09-03 12:44:52.948 -04:00 [INF] Authorization failed for the request at filter 'Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.AutoValidateAntiforgeryTokenAuthorizationFilter'.
2024-09-03 12:44:52.950 -04:00 [INF] Executing StatusCodeResult, setting HTTP status code 400
2024-09-03 12:44:52.952 -04:00 [INF] Executed page /_Host in 7.0733ms
2024-09-03 12:44:52.952 -04:00 [INF] Executed endpoint '/_Host'
2024-09-03 12:44:54.421 -04:00 [INF] Executing endpoint '/_Host'
2024-09-03 12:44:54.422 -04:00 [INF] Route matched with {page = "/_Host", action = "", controller = ""}. Executing page /_Host
2024-09-03 12:44:54.422 -04:00 [INF] Antiforgery token validation failed. The required antiforgery cookie ".AspNetCore.Antiforgery.eMUepvB4I2Y" is not present.
Microsoft.AspNetCore.Antiforgery.AntiforgeryValidationException: The required antiforgery cookie ".AspNetCore.Antiforgery.eMUepvB4I2Y" is not present.
   at Microsoft.AspNetCore.Antiforgery.DefaultAntiforgery.ValidateRequestAsync(HttpContext httpContext)
   at Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.ValidateAntiforgeryTokenAuthorizationFilter.OnAuthorizationAsync(AuthorizationFilterContext context)
2024-09-03 12:44:54.422 -04:00 [INF] Authorization failed for the request at filter 'Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.AutoValidateAntiforgeryTokenAuthorizationFilter'.
2024-09-03 12:44:54.422 -04:00 [INF] Executing StatusCodeResult, setting HTTP status code 400
2024-09-03 12:44:54.423 -04:00 [INF] Executed page /_Host in 0.5501ms
2024-09-03 12:44:54.423 -04:00 [INF] Executed endpoint '/_Host'
2024-09-03 12:44:55.923 -04:00 [INF] Executing endpoint '/_Host'
2024-09-03 12:44:55.923 -04:00 [INF] Route matched with {page = "/_Host", action = "", controller = ""}. Executing page /_Host
2024-09-03 12:44:55.923 -04:00 [INF] Antiforgery token validation failed. The required antiforgery cookie ".AspNetCore.Antiforgery.eMUepvB4I2Y" is not present.
Microsoft.AspNetCore.Antiforgery.AntiforgeryValidationException: The required antiforgery cookie ".AspNetCore.Antiforgery.eMUepvB4I2Y" is not present.
   at Microsoft.AspNetCore.Antiforgery.DefaultAntiforgery.ValidateRequestAsync(HttpContext httpContext)
   at Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.ValidateAntiforgeryTokenAuthorizationFilter.OnAuthorizationAsync(AuthorizationFilterContext context)
2024-09-03 12:44:55.923 -04:00 [INF] Authorization failed for the request at filter 'Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.AutoValidateAntiforgeryTokenAuthorizationFilter'.
2024-09-03 12:44:55.923 -04:00 [INF] Executing StatusCodeResult, setting HTTP status code 400
2024-09-03 12:44:55.923 -04:00 [INF] Executed page /_Host in 0.4511ms
2024-09-03 12:44:55.923 -04:00 [INF] Executed endpoint '/_Host'
2024-09-03 12:44:58.961 -04:00 [INF] Scheduling script 1 on schedule */10 7-17 * * 1-5 with time zone America/New_York.
2024-09-03 12:44:58.962 -04:00 [INF] Scheduling job 'PLC-UserID' with schedule PLC-UserID on time zone America/New_York
2024-09-03 12:44:58.969 -04:00 [INF] Scheduling script 17 on schedule */10 7-17 * * 1-5 with time zone America/New_York.
2024-09-03 12:44:58.969 -04:00 [INF] Scheduling job 'PGF-UserID' with schedule PGF-UserID on time zone America/New_York
2024-09-03 12:44:58.972 -04:00 [INF] Scheduling script 3 on schedule 0 2 * * * with time zone America/New_York.
2024-09-03 12:44:58.972 -04:00 [INF] Scheduling job 'Daily at 2am' with schedule Daily at 2am on time zone America/New_York
2024-09-03 12:44:58.975 -04:00 [INF] Scheduling script 12 on schedule 0 */2 * * * with time zone America/New_York.
2024-09-03 12:44:58.975 -04:00 [INF] Scheduling job 'Every 2 Hours' with schedule Every 2 Hours on time zone America/New_York
2024-09-03 12:44:58.976 -04:00 [INF] Scheduling script 16 on schedule 0 0 * * * with time zone America/New_York.
2024-09-03 12:44:58.976 -04:00 [INF] Scheduling job 'Nightly Palo Alto Configuration Downloads' with schedule Nightly Palo Alto Configuration Downloads on time zone America/New_York
2024-09-03 12:45:00.761 -04:00 [INF] Configuring authentication methods...
2024-09-03 12:45:00.768 -04:00 [INF] Synchronizing with git...
2024-09-03 12:45:00.770 -04:00 [INF] Running git sync, if configured.
2024-09-03 12:45:00.774 -04:00 [INF] Logging enabled at level Debug
2024-09-03 12:45:01.402 -04:00 [INF] Scheduling git sync service.
2024-09-03 12:45:01.402 -04:00 [INF] Scheduling background jobs...
2024-09-03 12:45:01.407 -04:00 [INF] Scheduling heartbeat job.
2024-09-03 12:45:01.422 -04:00 [INF] Scheduling update check.
2024-09-03 12:45:01.424 -04:00 [INF] Starting security service...
2024-09-03 12:45:01.427 -04:00 [INF] Starting security proxy.
2024-09-03 12:45:01.430 -04:00 [INF] Starting heartbeat job.
2024-09-03 12:45:01.431 -04:00 [INF] Running health check: CPU Usage
2024-09-03 12:45:01.453 -04:00 [INF] Finished heartbeat job.
2024-09-03 12:45:01.673 -04:00 [INF] Port set to 56797
2024-09-03 12:45:01.690 -04:00 [INF] Starting module discovery using Process.
2024-09-03 12:45:01.694 -04:00 [INF] Starting module discovery using Process.
2024-09-03 12:45:01.698 -04:00 [INF] Starting module discovery using Process.
2024-09-03 12:45:01.705 -04:00 [INF] Starting module discovery using Process.
2024-09-03 12:45:01.717 -04:00 [INF] Startup complete.
2024-09-03 12:45:02.728 -04:00 [INF] Running health check: Memory Utilization
2024-09-03 12:45:02.821 -04:00 [INF] Running health check: Disk Space
2024-09-03 12:45:02.824 -04:00 [INF] Running health check: PSScriptAnalyzer
2024-09-03 12:45:02.850 -04:00 [INF] Running health check: Conflicting Module
2024-09-03 12:45:02.862 -04:00 [INF] Running health check: Missing Environment
2024-09-03 12:45:06.596 -04:00 [INF] Starting groom job.
2024-09-03 12:45:06.598 -04:00 [INF] Script PLC - Get Mist Clients.ps1 has a max history of 100
2024-09-03 12:45:06.626 -04:00 [INF] Script has 0 jobs to delete.
2024-09-03 12:45:06.626 -04:00 [INF] Script Map 365 Tenants.ps1 has a max history of 100
2024-09-03 12:45:06.628 -04:00 [INF] Script has 0 jobs to delete.
2024-09-03 12:45:06.628 -04:00 [INF] Script M365DocsAutomation.ps1 has a max history of 100
2024-09-03 12:45:06.630 -04:00 [INF] Script has 0 jobs to delete.
2024-09-03 12:45:06.630 -04:00 [INF] Script WarrantyUpdate.ps1 has a max history of 100
2024-09-03 12:45:06.630 -04:00 [INF] Script has 0 jobs to delete.
2024-09-03 12:45:06.630 -04:00 [INF] Script CleanupLiongardServerNames.ps1 has a max history of 100
2024-09-03 12:45:06.631 -04:00 [INF] Script has 0 jobs to delete.
2024-09-03 12:45:06.631 -04:00 [INF] Script SpecificClientsM365DocsAutomation.ps1 has a max history of 100
2024-09-03 12:45:06.632 -04:00 [INF] Script has 0 jobs to delete.
2024-09-03 12:45:06.632 -04:00 [INF] Script DownloadPaloAltoConfig.ps1 has a max history of 100
2024-09-03 12:45:06.650 -04:00 [INF] Script has 0 jobs to delete.
2024-09-03 12:45:06.650 -04:00 [INF] Script JobFail.ps1 has a max history of 100
2024-09-03 12:45:06.650 -04:00 [INF] Script has 0 jobs to delete.
2024-09-03 12:45:06.650 -04:00 [INF] Script AddMissingWebsites.ps1 has a max history of 100
2024-09-03 12:45:06.652 -04:00 [INF] Script has 0 jobs to delete.
2024-09-03 12:45:06.652 -04:00 [INF] Script HCGDocsM365Automation.ps1 has a max history of 100
2024-09-03 12:45:06.653 -04:00 [INF] Script has 0 jobs to delete.
2024-09-03 12:45:06.653 -04:00 [INF] Script HuduMagicDashCompanyServices.ps1 has a max history of 100
2024-09-03 12:45:06.654 -04:00 [INF] Script has 0 jobs to delete.
2024-09-03 12:45:06.654 -04:00 [INF] Script VeeamBackupStatus.ps1 has a max history of 100
2024-09-03 12:45:06.657 -04:00 [INF] Script has 0 jobs to delete.
2024-09-03 12:45:06.657 -04:00 [INF] Script PrintSecrets.ps1 has a max history of 100
2024-09-03 12:45:06.658 -04:00 [INF] Script has 0 jobs to delete.
2024-09-03 12:45:06.658 -04:00 [INF] Script Bulk Add Zones.ps1 has a max history of 100
2024-09-03 12:45:06.659 -04:00 [INF] Script has 0 jobs to delete.
2024-09-03 12:45:06.659 -04:00 [INF] Script BulkUpdateFields.ps1 has a max history of 100
2024-09-03 12:45:06.659 -04:00 [INF] Script has 0 jobs to delete.
2024-09-03 12:45:06.659 -04:00 [INF] Script BulkDownloadPaloAltoConfig.ps1 has a max history of 100
2024-09-03 12:45:06.661 -04:00 [INF] Script has 0 jobs to delete.
2024-09-03 12:45:06.661 -04:00 [INF] Script PGF - Get Mist Clients.ps1 has a max history of 100
2024-09-03 12:45:06.664 -04:00 [INF] Script has 0 jobs to delete.
2024-09-03 12:45:06.666 -04:00 [INF] Groom date is: 8/4/2024 4:45:06 PM
2024-09-03 12:45:06.739 -04:00 [INF] Failed to delete computer WIN-D1AJDHHLGNL.
Microsoft.EntityFrameworkCore.DbUpdateException: An error occurred while saving the entity changes. See the inner exception for details.
 ---> Microsoft.Data.Sqlite.SqliteException (0x80004005): SQLite Error 19: 'FOREIGN KEY constraint failed'.
   at Microsoft.Data.Sqlite.SqliteException.ThrowExceptionForRC(Int32 rc, sqlite3 db)
   at Microsoft.Data.Sqlite.SqliteDataReader.NextResult()
   at Microsoft.Data.Sqlite.SqliteCommand.ExecuteReader(CommandBehavior behavior)
   at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteReader(RelationalCommandParameterObject parameterObject)
   at Microsoft.EntityFrameworkCore.Update.ReaderModificationCommandBatch.Execute(IRelationalConnection connection)
   --- End of inner exception stack trace ---
   at Microsoft.EntityFrameworkCore.Update.ReaderModificationCommandBatch.Execute(IRelationalConnection connection)
   at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.Execute(IEnumerable`1 commandBatches, IRelationalConnection connection)
   at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(IList`1 entriesToSave)
   at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(StateManager stateManager, Boolean acceptAllChangesOnSuccess)
   at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(Boolean acceptAllChangesOnSuccess)
   at Microsoft.EntityFrameworkCore.DbContext.SaveChanges(Boolean acceptAllChangesOnSuccess)
   at PowerShellUniversal.Extensibility.EFTable`2.SaveWithRetry(DbContext context) in C:\actions-runner\_work\universal\universal\src\PowerShellUniversal.Extensibility\Persistence\EFTable.cs:line 597
   at PowerShellUniversal.Extensibility.EFTable`2.Delete(T item) in C:\actions-runner\_work\universal\universal\src\PowerShellUniversal.Extensibility\Persistence\EFTable.cs:line 130
   at UniversalAutomation.GroomService.GroomComputers() in C:\actions-runner\_work\universal\universal\src\Universal.Server\Services\GroomService.cs:line 31
2024-09-03 12:45:06.758 -04:00 [INF] Finished groom job.

I’m going to have to revert back to 4.3.4 for the time being since this is causing so many issues. I may stand up a new server to start clean with, to see if it behaves differently. Could just be something due to the upgrade versus a fresh install, like you said.

Edit: I’m going to give it another shot, in order to test something out that I noticed while looking at logs and the database.

Edit 2: Still no luck. The "Bad gRPC response. HTTP status code: 500 " responses continue.

Edit 3: I’ve gone ahead with reverting back to 4.3.4. I’m thinking about standing up a new host to install 5.0.x on in a completely clean state to rule out anything that’s been done to the existing host or anything having to be “converted” from the 4.x install. I’ve actually already got a spare VM that was from a Jenkins PoC I did before we found PSU, so I’m going to repurpose that for a PSU v5 setup to see what happens.

I have now discovered that the showing/not-showing of the notification window with the token is (for some reason) determined by the Description of the token, and whether there is a duplicate description (whether active or revoked) in the database already. If you use a duplicate name, no notification is shown; if it’s a new name, the notification is shown. It seems to be identity-specific, too, but I haven’t tested that part out yet.

Update: I’ve installed PSU 5.0.5 on our old Jenkins host as a test, since it’s never had PSU installed before, created a test API and a test script to be called by the API, an app token tied to the local admin account, and then tested accessing the API. I did not run into any issues.

I then created a self-signed cert to bind to PSU (this is slightly different, as the production PSU instance uses a Let’s Encrypt cert, but should otherwise be the same effect), and retested accessing the API over HTTPS after adding -TrustCertificate to the Invoke-PSUScript line in the API, and I still didn’t run into any issues.

Seeing that in a clean install everything works without the gRPC errors, I will likely be mimicking the setup on the production server with a new database file (to rule out any possible corruption being transferred), delete all other files related to PSU, and install 5.0.x as a clean install.

2 Likes