Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Added StackTrace multiple locations in source code to assist when troubleshooting #1468

Open
wants to merge 3 commits into
base: main
Choose a base branch
from

Conversation

tkol2022
Copy link
Collaborator

@tkol2022 tkol2022 commented Dec 10, 2024

🗣 Description

Added the Powershell error stack trace to numerous locations in the source code to assist when troubleshooting bug reports.

I removed the try catch {} blocks in the following functions since the calling functions handle the stacktrace now: Get-PrivilegedUser, Get-PrivilegedRole, Invoke-Rego.

Closes #1344

💭 Motivation and context

🧪 Developer Testing

I tested an error scenario or two for each of the functions that I modified to add the stacktrace and verified that the error information was displayed as expected. Results are documented in this PR.

🧪 Instructions for Reviewers

  • Perform a code review to determine if any tweaks need to be made
  • Conduct hands on tests by simulating error conditions and verify that ScubaGear prints the error message and stacktrace. You can use my test results as inspiration.

✅ Pre-approval checklist

  • This PR has an informative and human-readable title.
  • PR targets the correct parent branch (e.g., main or release-name) for merge.
  • Changes are limited to a single goal - eschew scope creep!
  • Changes are sized such that they do not touch excessive number of files.
  • All future TODOs are captured in issues, which are referenced in code comments.
  • These code changes follow the ScubaGear content style guide.
  • Related issues these changes resolve are linked preferably via closing keywords.
  • All relevant type-of-change labels added.
  • All relevant project fields are set.
  • All relevant repo and/or project documentation updated to reflect these changes.
  • Unit tests added/updated to cover PowerShell and Rego changes.
  • Functional tests added/updated to cover PowerShell and Rego changes.
  • All relevant functional tests passed.
  • All automated checks (e.g., linting, static analysis, unit/smoke tests) passed.

✅ Pre-merge checklist

  • PR passed smoke test check.

  • Feature branch has been rebased against changes from parent branch, as needed

    Use Rebase branch button below or use this reference to rebase from the command line.

  • Resolved all merge conflicts on branch

  • Notified merge coordinator that PR is ready for merge via comment mention

  • Demonstrate changes to the team for questions and comments.
    (Note: Only required for issues of size Medium or larger)

✅ Post-merge checklist

  • Feature branch deleted after merge to clean up repository.
  • Verified that all checks pass on parent branch (e.g., main or release-name) after merge.

@tkol2022 tkol2022 marked this pull request as draft December 10, 2024 20:47
@tkol2022 tkol2022 changed the title stacktrace added to TryCommand and select locations in AAD provider Added StackTrace multiple locations in source code to assist when troubleshooting Dec 10, 2024
@tkol2022
Copy link
Collaborator Author

tkol2022 commented Dec 10, 2024

Tested scenario - AAD ExportCapPolicies returns empty table

Expected result: make sure warning message displays, execution does not stop. No errors are thrown in this scenario.
Actual result: everything occurred as expected

image

image

image

@tkol2022
Copy link
Collaborator Author

tkol2022 commented Dec 10, 2024

Tested scenario - AAD ExportCapPolicies returns invalid JSON

Expected result: make sure warning message displays with the error message, stacktrace and execution does not stop.
Actual result: Everything happens as expected.

image

image

image

@tkol2022
Copy link
Collaborator Author

tkol2022 commented Dec 10, 2024

Tested scenario - AAD Error occurs inside Get-PrivilegedUser

Expected result: make sure warning message displays with the error message, stacktrace and execution does not stop. Report indicates that the commands failed in the respective policies.
Actual result: Everything happened as expected.

image

image

image

Second scenario - Error occurs inside a Get-PrivilegedUser nested function

Expected result: make sure warning message displays with the error message, stacktrace and execution does not stop. Report indicates that the commands failed in the respective policies.
Actual result: Everything happened as expected.

image

image

@tkol2022
Copy link
Collaborator Author

tkol2022 commented Dec 10, 2024

Tested scenario - AAD Error occurs inside Get-PrivilegedRole

Expected result: make sure warning message displays with the error message, stacktrace and execution does not stop. Report indicates that the commands failed in the respective policies.
Actual result: Everything happened as expected.

image

image

image

Second scenario - occurs inside Get-PrivilegedRole nested function

Expected result: make sure warning message displays with the error message, stacktrace and execution does not stop. Report indicates that the commands failed in the respective policies.
Actual result: Everything happened as expected.

image

image

@tkol2022
Copy link
Collaborator Author

tkol2022 commented Dec 10, 2024

Tested scenario - Error occurs inside AAD Get-TenantDetail

Expected result: make sure warning message displays with the error message, stacktrace and execution does not stop.
Actual result: Everything happened as expected.

image

image

image

image

image

image

@tkol2022
Copy link
Collaborator Author

Tested scenario - Defender Error occurs inside top level code - Invalid or missing Cmdlet

Expected result: make sure warning message displays with the error message, stacktrace and execution does not stop. Report contains respective policy error.
Actual result: Everything happened as expected.

image

image

image

@tkol2022
Copy link
Collaborator Author

Tested scenario - Defender Error occurs connecting to ExchangeOnline

Expected result: make sure warning message displays with the error message, stacktrace and execution does not stop.
Actual result: Everything happened as expected.

image

image

@tkol2022
Copy link
Collaborator Author

Tested scenario - Defender Error occurs connecting to Connect-IPPSSession

Expected result: make sure warning message displays with the error message, stacktrace and execution does not stop. Report displays respective errors.
Actual result: Everything happened as expected.

image

image

image

@tkol2022
Copy link
Collaborator Author

Tested scenario - EXO Error occurs inside top level code - Invalid or missing Cmdlet

Expected result: make sure warning message displays with the error message, stacktrace and execution does not stop. Report contains respective policy error.
Actual result: Everything happened as expected.

image

image

image

@tkol2022
Copy link
Collaborator Author

tkol2022 commented Dec 10, 2024

Tested scenario - EXO Error occurs inside Get-EXOTenantDetail

Expected result: make sure warning message displays with the error message, stacktrace and execution does not stop. Report contains respective Tenant ID error.
Actual result: Everything happened as expected.

image

image

image

image

image

image

@tkol2022
Copy link
Collaborator Author

Tested scenario - Sharepoint Error occurs inside top level code - Invalid or missing Cmdlet

Expected result: make sure warning message displays with the error message, stacktrace and execution does not stop. Report contains respective policy error.
Actual result: Everything happened as expected.

image

image

image

@tkol2022
Copy link
Collaborator Author

tkol2022 commented Dec 10, 2024

Tested scenario - Teams Error occurs inside top level code - Invalid or missing Cmdlet

Expected result: make sure warning message displays with the error message, stacktrace and execution does not stop. Report contains respective policy error.
Actual result: Everything happened as expected.

image

image

image

Second scenario - Teams Error occurs inside nested function Get-TeamsTenantDetail

Expected result: make sure warning message displays with the error message, stacktrace and execution does not stop. Report contains respective error.
Actual result: Everything happened as expected.

image

image

image

@tkol2022
Copy link
Collaborator Author

tkol2022 commented Dec 10, 2024

Tested scenario - PowerPlatform Error occurs inside top level code - Invalid or missing Cmdlet

Expected result: make sure warning message displays with the error message, stacktrace and execution does not stop. Report contains respective policy error.
Actual result: Everything happened as expected.

image

image

image
image

Second scenario - PowerPlatform Error occurs inside Get-PowerPlatformTenantDetail

Expected result: make sure warning message displays with the error message, stacktrace and execution does not stop. Report contains respective error.
Actual result: Everything happened as expected.

image

image

image

@tkol2022
Copy link
Collaborator Author

Tested scenario - Connection > Disconnect-SCuBATenant

Expected result: make sure warning message displays with the error message, stacktrace.
Actual result: Everything happened as expected.

image

image

@tkol2022
Copy link
Collaborator Author

Tested scenario - Connection > Connect-Tenant

Expected result: make sure warning message displays with the error message, stacktrace.
Actual result: Everything happened as expected.

image

image

@tkol2022
Copy link
Collaborator Author

tkol2022 commented Dec 11, 2024

Tested scenario - Orchestrator > Invoke-ProviderList - inner try catch {} nested in foreach loop

Expected result: make sure warning message displays with the error message, stacktrace when executing one of the providers. Execution continues.
Actual result: Everything happened as expected.

image

image

Tested scenario - Orchestrator > Invoke-ProviderList - outer try catch {}

Expected result: make sure custom message displays with the error message, stacktrace and execution stops because completing the provider is a critical task.
Actual result: Everything happened as expected.

image

image

@tkol2022
Copy link
Collaborator Author

tkol2022 commented Dec 11, 2024

Tested scenario - Orchestrator > Invoke-RunRego - All products failed inside foreach loop

Expected result: make sure warning message displays with the error message, stacktrace and execution stops since all providers failed.
Actual result: Everything happened as expected.

image

image

Tested scenario - Orchestrator > Invoke-RunRego - A single product failed inside foreach loop

Expected result: make sure warning message displays with the error message, stacktrace and execution continues since only a single provider failed.
Actual result: Everything happened as expected.

image

image

image

Tested scenario - Orchestrator > Invoke-RunRego - Error occurred in outer catch {} block

Expected result: make sure custom message displays with the error message, stacktrace and execution stops since creating the Rego results json file is critical.
Actual result: Everything happened as expected.

image

image

@tkol2022
Copy link
Collaborator Author

Tested scenario - Orchestrator > ConvertTo-ResultsCsv - All products failed

Expected result: make sure warning message displays with the error message, stacktrace and execution does not stop since creating the CSV is not a critical task.
Actual result: Everything happened as expected.

image

image

image

@tkol2022
Copy link
Collaborator Author

tkol2022 commented Dec 11, 2024

TODO - Future enhancements

The following items were observed as I was working this PR that I feel would be some good enhancements to the error handling logic in future issues.

Item 1 - Prevent duplicate error message displays from Merge-JsonOutput

When an error occurs in this function, it gets displayed twice in the console which really clouds up the output. It would be ideal to only display the same error message once. I believe this occurs because there is no catch {} block in the calling function Invoke-Scuba so what ends up happening is that the thrown error gets displayed a second time by Powershell itself.

image

Item 2 - Write powershell unit tests to exercise all the various exception blocks and ensure that they display the stacktrace and error message.

Item 3 - In Orchestrator > Invoke-ProviderList if ALL of the providers fail, the Orchestrator should stop execution instead of trying to proceed.

Item 4 - We should probably standardize when we display an error message using Write-Warning versus Write-Error to be consistent

@tkol2022
Copy link
Collaborator Author

Tested scenario - Orchestrator > Merge-JsonOutput - path length error occurred

Expected result: make sure custom path message displays with the error message, stacktrace and execution stops since merging the JSON is a critical task.
Actual result: Everything happened as expected.

image
image

image

Second scenario - Orchestrator > Merge-JsonOutput - generic error occurred

Expected result: make sure generic message displays with the error message, stacktrace and execution stops since merging the JSON is a critical task.
Actual result: Everything happened as expected.

image

@tkol2022
Copy link
Collaborator Author

Tested scenario - Orchestrator > Invoke-ReportCreation - error occurred

Expected result: make sure custom message displays with the error message, stacktrace and execution stops since creating the report is a critical task.
Actual result: Everything happened as expected.

image

image

@tkol2022
Copy link
Collaborator Author

Tested scenario - Orchestrator > Import-Resources - error occurred

Expected result: make sure custom message displays with the error message, stacktrace and execution stops since importing modules is a critical task.
Actual result: Everything happened as expected.

image

image

@tkol2022
Copy link
Collaborator Author

Tested scenario - RunRego.psm1 > Invoke-Rego - error occurred

Expected result: I removed the try catch logic from this function since the calling function already has it so make the error message and stacktrace display and execution stops since invoking Rego is a critical task.
Actual result: Everything happened as expected.

image

image

@tkol2022 tkol2022 added the enhancement This issue or pull request will add new or improve existing functionality label Dec 12, 2024
@tkol2022 tkol2022 assigned twneale and unassigned ehaines1 Dec 12, 2024
Copy link
Collaborator

@schrolla schrolla left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Completed code review and all looked good, with exception of wanting a format change to how stacktraces are shown. Makes for a single warning with the exception message, but adding newline between message and trace for clearer flow, particularly when there are multiple traces.
Will review operational test cases as part of review part 2 separately, but wanted to get these in ASAP.

Comment on lines +225 to +226
Write-Warning "Error establishing a connection with $($Product): $($_.Exception.Message)"
Write-Warning "Stacktrace: $($_.ScriptStackTrace)"
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I would recommend a slightly different format for showing the stacktrace to make it more consistent with the way they are typically shown in other programs. In those cases, the stacktrace (when included) immediately follows and is part of the exception message in a format like:
Exception Message
StackTrace
This makes it easier to pair the trace with the error message, and prevents additional WARNING: prepends on the stacktrace. So it's easy to see where the trace begins and ends. The new format could look like this:

Suggested change
Write-Warning "Error establishing a connection with $($Product): $($_.Exception.Message)"
Write-Warning "Stacktrace: $($_.ScriptStackTrace)"
Write-Warning "Error establishing a connection with $($Product): $($_.Exception.Message)`n$($_.ScriptStackTrace)"

Here's an example of what that looks like
Screenshot 2024-12-12 at 10 18 31 AM

This would also apply to all occurrences for consistency.

Comment on lines +303 to +304
Write-Warning "ERROR: Could not disconnect from $Product`n: $($_.Exception.Message)"
Write-Warning "Stacktrace: $($_.ScriptStackTrace)"
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I know the ERROR was there previously, but since this is actually a warning AND since it's already pre-pended with WARNING, I'd recommend removing the 'ERROR:' bit as it seems contradictory and redundant.
Also including previously mentioned format change recommendation.

Suggested change
Write-Warning "ERROR: Could not disconnect from $Product`n: $($_.Exception.Message)"
Write-Warning "Stacktrace: $($_.ScriptStackTrace)"
Write-Warning "Could not disconnect from $Product`n: $($_.Exception.Message)`n$($_.ScriptStackTrace)"

Comment on lines +641 to +642
Write-Warning "Error with the $($BaselineName) Provider: $($_.Exception.Message)"
Write-Warning "Stacktrace: $($_.ScriptStackTrace)"
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Format update recommendation

Suggested change
Write-Warning "Error with the $($BaselineName) Provider: $($_.Exception.Message)"
Write-Warning "Stacktrace: $($_.ScriptStackTrace)"
Write-Warning "Error with the $($BaselineName) Provider: $($_.Exception.Message)`n$($_.ScriptStackTrace)"

Comment on lines +690 to +691
Ending ScubaGear execution. Error: $($_.Exception.Message) `
Stacktrace: $($_.ScriptStackTrace)"
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Format update recommendation, because of the line break not 100% this works as shown without some tweaking.

Suggested change
Ending ScubaGear execution. Error: $($_.Exception.Message) `
Stacktrace: $($_.ScriptStackTrace)"
Ending ScubaGear execution. Error: $($_.Exception.Message)`
`n$($_.ScriptStackTrace)"

Comment on lines +773 to +774
Write-Warning "Error with the $($BaselineName) Rego invocation: $($_.Exception.Message)"
Write-Warning "Stacktrace: $($_.ScriptStackTrace)"
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Format update recommendation

Suggested change
Write-Warning "Error with the $($BaselineName) Rego invocation: $($_.Exception.Message)"
Write-Warning "Stacktrace: $($_.ScriptStackTrace)"
Write-Warning "Error with the $($BaselineName) Rego invocation: $($_.Exception.Message)`n$($_.ScriptStackTrace)"

Comment on lines +137 to +138
Write-Warning "Error retrieving Tenant details using Get-EXOTenantDetail: $($_.Exception.Message)"
Write-Warning "Stacktrace: $($_.ScriptStackTrace)"
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Format update recommendation

Suggested change
Write-Warning "Error retrieving Tenant details using Get-EXOTenantDetail: $($_.Exception.Message)"
Write-Warning "Stacktrace: $($_.ScriptStackTrace)"
Write-Warning "Error retrieving Tenant details using Get-EXOTenantDetail: $($_.Exception.Message)`n$($_.ScriptStackTrace)"

Comment on lines +255 to +256
Write-Warning "Error retrieving Tenant details using Get-PowerPlatformTenantDetail: $($_.Exception.Message)"
Write-Warning "Stacktrace: $($_.ScriptStackTrace)"
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Format update recommendation

Suggested change
Write-Warning "Error retrieving Tenant details using Get-PowerPlatformTenantDetail: $($_.Exception.Message)"
Write-Warning "Stacktrace: $($_.ScriptStackTrace)"
Write-Warning "Error retrieving Tenant details using Get-PowerPlatformTenantDetail: $($_.Exception.Message)`n$($_.ScriptStackTrace)"

Comment on lines +85 to +86
Write-Warning "Error retrieving Tenant details in Get-TeamsTenantDetail: $($_.Exception.Message)"
Write-Warning "Stacktrace: $($_.ScriptStackTrace)"
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Format update recommendation

Suggested change
Write-Warning "Error retrieving Tenant details in Get-TeamsTenantDetail: $($_.Exception.Message)"
Write-Warning "Stacktrace: $($_.ScriptStackTrace)"
Write-Warning "Error retrieving Tenant details in Get-TeamsTenantDetail: $($_.Exception.Message)`n$($_.ScriptStackTrace)"

Comment on lines +27 to +28
Write-Warning "Error running $($Command): $($_.Exception.Message)"
Write-Warning "Stacktrace: $($_.ScriptStackTrace)"
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Format update recommendation

Suggested change
Write-Warning "Error running $($Command): $($_.Exception.Message)"
Write-Warning "Stacktrace: $($_.ScriptStackTrace)"
Write-Warning "Error running $($Command): $($_.Exception.Message)`n$($_.ScriptStackTrace)"

@@ -85,7 +85,7 @@ InModuleScope Orchestrator {
}
{ ConvertTo-ResultsCsv @CsvParameters} | Should -Not -Throw
Should -Invoke -CommandName Format-PlainText -Exactly -Times 0
Should -Invoke -CommandName Write-Warning -Exactly -Times 1
Should -Invoke -CommandName Write-Warning -Exactly -Times 2
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

With the format update recommendation, this would likely revert back to 1 Times since there would be a single Write-Warning call to print both the exception message and stack trace.

Suggested change
Should -Invoke -CommandName Write-Warning -Exactly -Times 2
Should -Invoke -CommandName Write-Warning -Exactly -Times 1

@schrolla
Copy link
Collaborator

schrolla commented Dec 12, 2024

TODO - Future enhancements

The following items were observed as I was working this PR that I feel would be some good enhancements to the error handling logic in future issues.

Item 1 - Prevent duplicate error message displays from Merge-JsonOutput

When an error occurs in this function, it gets displayed twice in the console which really clouds up the output. It would be ideal to only display the same error message once. I believe this occurs because there is no catch {} block in the calling function Invoke-Scuba so what ends up happening is that the thrown error gets displayed a second time by Powershell itself.

<snip - see original comment for full image >

Item 2 - Write powershell unit tests to exercise all the various exception blocks and ensure that they display the stacktrace and error message.

Item 3 - In Orchestrator > Invoke-ProviderList if ALL of the providers fail, the Orchestrator should stop execution instead of trying to proceed.

Item 4 - We should probably standardize when we display an error message using Write-Warning versus Write-Error to be consistent

I'd recommend we link these TODOs to the follow-on reformulated issue related to the existing #1344. Mentioning here so the reference is in #1344 when it gets reviewed for closure and reformulation.

@schrolla
Copy link
Collaborator

I think the solution here is a separate catch block specifically for the type of exception thrown when max file length is exceeded. That catch block can include what's in the if statement and shed the outer exception message while still appending the stacktrace, then a general catch block that has the else statement. That's cleaner than trying to if/else since the catch mechanism already supports conditional catches based on error type.

Tested scenario - Orchestrator > Merge-JsonOutput - path length error occurred

Expected result: make sure custom path message displays with the error message, stacktrace and execution stops since merging the JSON is a critical task. Actual result: Everything happened as expected.

image image

image

Copy link
Collaborator

@schrolla schrolla left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Review Part 2 - Performed operational testing similar to the scenarios @tkol2022 put forth which were thorough. Spot checked redo of a few and got the same results as @tkol2022 which were as expected. Found one additional subordinate function to Invoke-SCuBA in Test case 3 below for revision to support consistency of error reporting format/feedback. See below.

Added the following scenarios which also performed as expected:

Test Scenario 1 - Invoking PowerPlatform with incorrect M365Environment (commercial) on G5 tenant

Resulted in throwing the correct warning and then failing ScubaGear overall as this was the only product selected for the run.
Screenshot 2024-12-12 at 2 33 44 PM

Test Scenario 2 - Compare-ProductList failure in Orchestrator Invoke-Scuba

This one causes Compare-ProductList function to throw an exception inside the Invoke-Scuba main try block. Since function only runs if a provider command fails, second throw added to TryCommand to force execution of Compare-ProductList code path. Results did not match expected format as other functions called directly from Orchestrator catch and emit their own exceptions.
Screenshot 2024-12-12 at 3 30 31 PM

Recommendation is to modify the Compare-ProductList function to catch and emit exception message and stacktrace rather than throwing its error for higher level handling.

Copy link
Collaborator

@nanda-katikaneni nanda-katikaneni left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Did multiple tests with following simulated errors: incorrect M365 environment, errors in get priv user roles, errors in connecting exo, opa path error, convert to csv errors.
In each case, the stack trace showed expected error trace.

Apart from Addam's suggestion for updating warning format, no new suggested changes from me. Nice work.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
enhancement This issue or pull request will add new or improve existing functionality
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Implement standardized error message output including the stacktrace
5 participants