christophwille / pscore-playground

Programmatically drive PS Core with C# (mostly Exchange Online Powershell 3 and later)
MIT License
2 stars 1 forks source link

3.4.0 to 3.5.0: Startup script error re-appears #8

Open christophwille opened 2 weeks ago

christophwille commented 2 weeks ago

Issue #4 has come up again for https://github.com/christophwille/pscore-playground/commit/d95d6ac691eefd5d7d6417aecaeeba5e68c71a58 - this time 3.4 works, but the newer 3.5 with the identical C# code and ConnectScript.ps1 is failing.

Exception thrown: 'System.Management.Automation.PSInvalidOperationException' in System.Management.Automation.dll
ExO3PsLib.ExchangeOnlineService: Error: Failure

System.Management.Automation.PSInvalidOperationException: Running startup script threw an error: Cannot add type. Compilation errors occurred..
 ---> System.Exception: Cannot add type. Compilation errors occurred.
   --- End of inner exception stack trace ---
   at System.Management.Automation.Runspaces.LocalRunspace.DoOpenHelper()
   at System.Management.Automation.Runspaces.LocalRunspace.OpenHelper(Boolean syncCall)
   at System.Management.Automation.Runspaces.RunspaceBase.CoreOpen(Boolean syncCall)
   at System.Management.Automation.Runspaces.RunspaceBase.Open()
   at System.Management.Automation.Runspaces.Internal.RunspacePoolInternal.CreateRunspace()
   at System.Management.Automation.Runspaces.Internal.RunspacePoolInternal.OpenHelper()
   at System.Management.Automation.Runspaces.Internal.RunspacePoolInternal.CoreOpen(Boolean isAsync, AsyncCallback callback, Object asyncState)
   at System.Management.Automation.Runspaces.Internal.RunspacePoolInternal.Open()
   at System.Management.Automation.Runspaces.RunspacePool.Open()
   at ExO3PsLib.ExchangeOnlinePowerShellFactory.OpenPool(String appId, String organization, X509Certificate2 certificate, String modulePath) in D:\GitWorkspace\pscore-playground\ExO3onNet8LocalModule\ExO3PsLib\ExchangeOnlinePowerShellFactory.cs:line 110
   at ExO3PsLib.ExchangeOnlinePowerShellFactory.ConnectViaPool(String appId, String organization, X509Certificate2 certificate, String modulePath) in D:\GitWorkspace\pscore-playground\ExO3onNet8LocalModule\ExO3PsLib\ExchangeOnlinePowerShellFactory.cs:line 117
   at ExO3PsLib.ExchangeOnlineService.GetExoMailbox() in D:\GitWorkspace\pscore-playground\ExO3onNet8LocalModule\ExO3PsLib\ExchangeOnlineService.cs:line 48
The thread '[Thread Destroyed]' (28616) has exited with code 0 (0x0).
christophwille commented 2 weeks ago

Current state of investigation as of https://github.com/christophwille/pscore-playground/commit/1aa0a2394551804512b5d0b778da96173d60b6ec:

The entire ConnectScript.ps1 runs to completion (verbose output below) properly (not shown, but I added a Write-Verbose at the end of ConnectScript.ps1 and that is printed as well):

VERBOSE: Computed version info: 3.5.0
VERBOSE: ModuleVersion: 3.5.0
Writing cmdlet logs to d:\EXO_RESTCmdletLogs-20240618-170821241.csv
VERBOSE: [ThreadID: #] Trying to get a new token from AAD
VERBOSE: [ThreadID: #] Trying to acquire token based on UI flow
VERBOSE: [ThreadID: #] Successfully acquired new token for Cert based flow.
VERBOSE: [ThreadID: #] Successfully got a token from AAD
VERBOSE: Exporting function 'Add-AvailabilityAddressSpace'.
VERBOSE: Exporting function 'Add-DistributionGroupMember'.
VERBOSE: Exporting function 'Add-MailboxFolderPermission'.
   removed a lot here
VERBOSE: Exporting function 'Set-Clutter'.
VERBOSE: Exporting function 'Set-FocusedInbox'.
VERBOSE: Exporting function 'Test-DlpPolicies'.
VERBOSE: Exporting function 'Test-Message'.
VERBOSE: Exporting variable 'HelpFileNames'.
VERBOSE: AutoGen EXOModule created at  C:\Users\christophw\AppData\Local\Temp\tmpEXO_zbcsmy20.ipa
VERBOSE: Running Configure-AppSettings
VERBOSE: Setting PrintWarningsReceivedFromServer to False
VERBOSE: PageSizes is set to: 1000
VERBOSE: Logs are generated at d:
VERBOSE: Log level set to All
VERBOSE: Updated Log file configuration to d:, 100000000, 2000000000, All
VERBOSE: TrackPerformance is set to: True
VERBOSE: ShowProgress is set to: False
VERBOSE: UseMultithreading is set to: True

Possibly to investigate:

                    if ($SkipLoadingCmdletHelp -eq $true)
                    {
                        $cmdletLogger.LogGenericInfo($connectionContextID, "Skipping cmdlet help data");
                    }

that doesn't show up in CSV log, all I get is


ExoModuleVersion:3.5.0;ConnectionID:d2efe7c0-21a9-4608-9918-bb5dd6e8714f
ClientRequestID,StartTime,EndTime,CmdletName,CmdletParameters,GenericInfo,GenericErrors,TotalTime
abc5d9ae-156a-467b-84be-798c9fe09ead,2024-06-18 17:08:23Z,2024-06-18 17:08:24Z,Get-ConnectionContext,ExchangeEnvironmentName:....
a4959fc5-b608-4c90-9348-c6686094fd1f,2024-06-18 17:08:24Z,2024-06-18 17:08:31Z,New-EXOModule,ConnectionContext:...
d2efe7c0-21a9-4608-9918-bb5dd6e8714f,2024-06-18 17:08:21Z,2024-06-18 17:08:31Z,Connect-ExchangeOnline,ConnectionUri:;...
christophwille commented 1 week ago

If I set (it is intentionally on true, and has been for years)

iss.ThrowOnRunspaceOpenError = false;

then Open() doesn't throw (expected), and the execution of the Get-EXOMailBox cmdlet works just fine. Puzzled.

christophwille commented 1 week ago

https://github.com/PowerShell/PowerShell/discussions/23976 maybe the next course of action has to be to debug into DoOpenHelper()....

christophwille commented 3 days ago

Code in question for 7.4.3 DoOpenHelper:

            // Now do initial state configuration that requires an active runspace
            Exception initError = InitialSessionState.BindRunspace(this, s_runspaceInitTracer);

https://github.com/PowerShell/PowerShell/blob/cb9a9831420e08553f0dee5d91de0c4f5ee0c93a/src/System.Management.Automation/engine/hostifaces/LocalConnection.cs#L695

executes

            // Process startup scripts
            if (StartupScripts.Count > 0)
            {
                Exception startupScriptException = ProcessStartupScripts(initializedRunspace);
                if (startupScriptException != null)
                {
                    runspaceInitTracer.WriteLine(
                        "Runspace open failed while running startup script: First error {1}",
                        startupScriptException);

                    Exception result = PSTraceSource.NewInvalidOperationException(startupScriptException, RemotingErrorIdStrings.StartupScriptThrewTerminatingError, startupScriptException.Message);
                    return result;
                }
            }

https://github.com/PowerShell/PowerShell/blob/cb9a9831420e08553f0dee5d91de0c4f5ee0c93a/src/System.Management.Automation/engine/InitialSessionState.cs#L2574-L2587

Question: can runspaceInitTracer be tapped? It might actually write the proper full exception instead just .Message.