Improve use of Write-Log and exceptions #97

danbelcher-MSFT · 2018-01-24T02:12:33Z

Previously, users of Write-Log were left to handle creating messages themselves when logging an exception. Typically, our use has been to extract the exception's message and log this string. The issue with this approach is that we lose other valuable information, such as the originating script, line, exception type, etc.

With this change, Write-Log now accepts a -Exception parameter and handles logging the full exception information. This new functionality works in combination with the existing -Message parameter, so that users can log some context before logging the exception information. We hope that this change will make debugging StoreBroker issues faster and more intuitive for the reader.

Additional changes:

Write-Log properly handles pipelining multiple strings to the -Message parameter.
Existing uses of Write-Log have been modified to use the new -Exception parameter where applicable.
Spaces have been made uniform across touched files.

…roper support of pipelining.

This optional parameter will enable easier logging of exception information. - Implement pipeline support for -Message parameter This parameter always accepted pipeline input but didn't follow existing PoSh paradigms for pipelining. Note that there is no performance benefit to pipelining, but the option is there. - Add Write-LogHelper. This cmdlet is not intended to be used by itself, but instead should support Write-Log. The cmdlet performs the actual act of writing to screen/log.

…ception parameter.

While it was nice to break things up, keeping the actual writing logic in Write-Log will lead to better exception information if the Write-* cmdlets fail, because the exception will show as originating from Write-Log (which makes sense), instead of Write-LogHelper (which makes less sense).

… in Invoke-SBRestMethod, etc.

HowardWolosky

This is a whole lot of goodness...thanks.
The space normalization is appreciated too. In the future though, it would be great to have that come in as a separate change.

HowardWolosky · 2018-01-25T23:17:42Z

StoreBroker/Helpers.ps1

+
+        Logs the message:
+
+        Write-LogHelper : 2018-01-23 12:57:37 : dabelc : There was a problem.


Not Write-LogHelper anymore, right?

HowardWolosky · 2018-01-25T23:20:21Z

StoreBroker/Helpers.ps1


        if ($global:SBShouldLogPid)
        {
-            $MaxPidDigits = 10 # This is an estimate (see https://stackoverflow.com/questions/17868218/what-is-the-maximum-process-id-on-windows)
-            $pidColumnLength = $MaxPidDigits + "[]".Length
+            $maxPidDigits = 10 # This is an estimate (see https://stackoverflow.com/questions/17868218/what-is-the-maximum-process-id-on-windows)


This had been capitalized to signify it as a constant

Then I'd say it failed to signify that because I thought it was using the parameter naming convention. Why not all caps? Or local variable naming convention and use Set-Variable with the Constant/ReadOnly option to show that the value shouldn't be changed?

At the time, I was unaware of the ReadOnly/Constant options for the -Option switch with Set-Variable....thanks for that. PowerShell best practices indicates PascalCase for constants.

Revert this change.

Use Set-Variable with ReadOnly

Let me know which you'd prefer.

HowardWolosky · 2018-01-25T23:22:19Z

StoreBroker/StoreIngestionApplicationApi.ps1

@@ -1142,7 +1142,7 @@ function Update-ApplicationSubmission
                $output = @()
                $output += "We can only modify a submission that is in the '$script:keywordPendingCommit' state."
                $output += "The submission that you requested to modify ($SubmissionId) is in '$($submissionToUpdate.status)' state."
-                
+
                $newLineOutput = ($output -join [Environment]::NewLine)


It seems like there are probably a lot of opportunities throughout the code to now remove this type of line and just directly pass-in the array of strings, now that Write-Log will take care of NewLine'ing them for the user.

Sure. I'll fix them.

…tents.

HowardWolosky · 2018-01-29T22:54:23Z

Extensions/ConvertFrom-ExistingIapSubmission.ps1

@@ -528,14 +526,13 @@ function Show-ImageFileNames
            $output += " * [$langCode]: " + ($LangImageNames.$langCode -join ", ")
        }

-        Write-Log $($output -join [Environment]::NewLine)
+        Write-Log $output


If you're here, I'd ask that you explicitly add the -Message at the same time, just to help us get up to the consistency we've been working towards.

I went all-in and replaced all instances of Write-Log that used implicit -Message parameter.

HowardWolosky · 2018-01-29T22:54:53Z

Extensions/ConvertFrom-ExistingSubmission.ps1

@@ -1058,14 +1056,13 @@ function Show-ImageFileNames
            $output += " * [$langCode]: " + ($LangImageNames.$langCode -join ", ")
        }

-        Write-Log $($output -join [Environment]::NewLine)
+        Write-Log $output


HowardWolosky · 2018-01-29T22:55:37Z

StoreBroker/StoreIngestionApi.psm1

@@ -1377,7 +1377,7 @@ function Start-SubmissionMonitor
                    $shouldMonitor = $false
                }

-                Write-Log $($body -join [Environment]::NewLine)
+                Write-Log $body


HowardWolosky

Only remaining thing would be to add the -Message to those simple Write-Log lines that you were touching, and then to run an internal build and validate that packaging/submission still works fine and that the logs look reasonable.

HowardWolosky · 2018-01-29T22:55:47Z

StoreBroker/StoreIngestionApplicationApi.ps1

@@ -300,7 +300,7 @@ function Format-Application

    End
    {
-       Write-Log $($output -join [Environment]::NewLine)
+       Write-Log $output


HowardWolosky · 2018-01-29T22:55:54Z

StoreBroker/StoreIngestionApplicationApi.ps1

@@ -524,7 +524,7 @@ function Format-ApplicationSubmission

    End
    {
-        Write-Log $($output -join [Environment]::NewLine)
+        Write-Log $output


HowardWolosky · 2018-01-29T22:58:04Z

StoreBroker/StoreIngestionFlightingApi.ps1

@@ -321,7 +321,7 @@ function Format-ApplicationFlight

    End
    {
-        Write-Log $($output -join [Environment]::NewLine)
+        Write-Log $output


HowardWolosky · 2018-01-29T22:58:17Z

StoreBroker/StoreIngestionFlightingApi.ps1

@@ -734,7 +733,7 @@ function Format-ApplicationFlightSubmission

    End
    {
-        Write-Log $($output -join [Environment]::NewLine)
+        Write-Log $output


HowardWolosky · 2018-01-29T22:58:56Z

StoreBroker/StoreIngestionIapApi.ps1

@@ -296,7 +296,7 @@ function Format-InAppProduct

    End
    {
-        Write-Log $($output -join [Environment]::NewLine)
+        Write-Log $output


HowardWolosky · 2018-01-29T22:59:00Z

StoreBroker/StoreIngestionIapApi.ps1

@@ -854,7 +854,7 @@ function Format-InAppProductSubmission

    End
    {
-        Write-Log $($output -join [Environment]::NewLine)
+        Write-Log $output


This commit replaces all (most?) instances of using Write-Log with implicit -Message parameter. Modified lines were found with the following regex replacement: Find : Write-Log\s([^-]) Replace: Write-Log -Message $1

Daniel Belcher added 6 commits January 23, 2018 13:59

Add -Exception parameter to Write-Log. Still need documentation and p…

90fba07

…roper support of pipelining.

- Modify existing calls to Write-Log to take advantage of the new -Ex…

68e4b2c

…ception parameter.

- Minor change to exception logging in Telemetry.ps1

5499dcb

- Revert changes to exception messages for complicated exceptiontypes…

e4f4aeb

… in Invoke-SBRestMethod, etc.

HowardWolosky requested changes Jan 25, 2018

View reviewed changes

- Rewrite existing uses of Write-Log that are joining the message con…

b158ca5

…tents.

HowardWolosky reviewed Jan 29, 2018

View reviewed changes

HowardWolosky approved these changes Jan 29, 2018

View reviewed changes

Daniel Belcher added 2 commits January 29, 2018 16:28

- Use explicit -Message parameer name with Write-Log

9732b47

This commit replaces all (most?) instances of using Write-Log with implicit -Message parameter. Modified lines were found with the following regex replacement: Find : Write-Log\s([^-]) Replace: Write-Log -Message $1

Bump module version to 1.14.0

79f2610

danbelcher-MSFT merged commit 340981e into microsoft:master Jan 30, 2018

danbelcher-MSFT deleted the user/dabelc/BetterExceptionLogging branch January 30, 2018 01:06

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Improve use of Write-Log and exceptions #97

Improve use of Write-Log and exceptions #97

danbelcher-MSFT commented Jan 24, 2018

HowardWolosky left a comment

HowardWolosky Jan 25, 2018

danbelcher-MSFT Jan 26, 2018

HowardWolosky Jan 25, 2018

danbelcher-MSFT Jan 26, 2018

HowardWolosky Jan 26, 2018

danbelcher-MSFT Jan 26, 2018

HowardWolosky Jan 25, 2018

danbelcher-MSFT Jan 26, 2018

danbelcher-MSFT Jan 26, 2018

HowardWolosky Jan 29, 2018

danbelcher-MSFT Jan 30, 2018

HowardWolosky Jan 29, 2018

HowardWolosky Jan 29, 2018

HowardWolosky left a comment

HowardWolosky Jan 29, 2018

HowardWolosky Jan 29, 2018

HowardWolosky Jan 29, 2018

HowardWolosky Jan 29, 2018

HowardWolosky Jan 29, 2018

HowardWolosky Jan 29, 2018


		Logs the message:

		Write-LogHelper : 2018-01-23 12:57:37 : dabelc : There was a problem.

Improve use of Write-Log and exceptions #97

Improve use of Write-Log and exceptions #97

Conversation

danbelcher-MSFT commented Jan 24, 2018

HowardWolosky left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

HowardWolosky left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment