Wednesday, December 9, 2015

Logging PowerShell Error Message Output

When designing a PowerShell script that will be executed as a scheduled task, I prefer copious amounts of logging, for obvious reasons. I recently had some fun with getting error messages logged with sufficient detail. Consider the following simple script:
$A = Get-ChildItem C:\temp
try {
 $B = Get-ChildItem2 C:\temp
} catch {
 $Error[0] | Out-File -filepath c:\temp\test.log
}

I have forced an error to occur on line 3 by including an invalid command. When run interactively no output is produced on the screen, which is fine because when run as a scheduled task, no one will be there to see it anyways. The log file contains the following content:
Get-ChildItem2 : The term 'Get-ChildItem2' is not recognized as the name of a cmdlet, function, script file, or
operable program. Check the spelling of the name, or if a path was included, verify that the path is correct and try
again.
At C:\Temp\test.ps1:3 char:7
+     $B = Get-ChildItem2 C:\temp
+          ~~~~~~~~~~~~~~
    + CategoryInfo          : ObjectNotFound: (Get-ChildItem2:String) [], CommandNotFoundException
    + FullyQualifiedErrorId : CommandNotFoundException
The output log contains the normal error detail you'd see if running the command interactively.


Let's enhance the log with something normal like a timestamp.
(get-date -UFormat "%Y%m%d%H%M%S") + ": " + $Error[0] | Out-File -filepath c:\temp\test.log

The output log now contains the content:
20151209123349: The term 'Get-ChildItem2' is not recognized as the name of a cmdlet, function, script file, or operable program. Check the spelling of the name, or if a path was included, verify that the path is correct and try again.
We successfully added the timestamp, but lost many details such as the line that incurred the error. Let's see if we can restore the missing data to the log file. When we look at the error object, we can see the following information:

PS C:\Temp> $Error[0] | gm

   TypeName: System.Management.Automation.ErrorRecord
Name                  MemberType     Definition
----                  ----------     ----------
Equals                Method         bool Equals(System.Object obj)
GetHashCode           Method         int GetHashCode()
GetObjectData         Method         void GetObjectData(System.Runtime.Serialization.SerializationInfo info, System....
GetType               Method         type GetType()
ToString              Method         string ToString()
CategoryInfo          Property       System.Management.Automation.ErrorCategoryInfo CategoryInfo {get;}
ErrorDetails          Property       System.Management.Automation.ErrorDetails ErrorDetails {get;set;}
Exception             Property       System.Exception Exception {get;}
FullyQualifiedErrorId Property       string FullyQualifiedErrorId {get;}
InvocationInfo        Property       System.Management.Automation.InvocationInfo InvocationInfo {get;}
PipelineIterationInfo Property       System.Collections.ObjectModel.ReadOnlyCollection[int] PipelineIterationInfo {g...
ScriptStackTrace      Property       string ScriptStackTrace {get;}
TargetObject          Property       System.Object TargetObject {get;}
PSMessageDetails      ScriptProperty System.Object PSMessageDetails {get=& { Set-StrictMode -Version 1; $this.Except...

We have a default to ToString() method.  Let's see what that gets us:
PS C:\Temp> $Error[0].ToString()
The term 'Get-ChildItem2' is not recognized as the name of a cmdlet, function, script file, or operable program. Check
the spelling of the name, or if a path was included, verify that the path is correct and try again.


That matches the text that ended up in the second log file. Let's see if we can find where the missing data lives in the ErrorRecord object. The initial output contains the keywords CategoryInfo and FullyQualifiedErrorId.  Those are both properties, so let's look at those:

PS C:\Temp> $Error[0].CategoryInfo

Category   : ObjectNotFound
Activity   :
Reason     : CommandNotFoundException
TargetName : Get-ChildItem2
TargetType : String

PS C:\Temp> $Error[0].FullyQualifiedErrorId
CommandNotFoundException


That's a start as that data is included in the initial output, but is unformatted.  We're still missing the pointer to the faulting line in the script. Looking through the other properties, we see that the InvocationInfo property contains the data we were looking for in the PositionMessage property.


PS C:\Temp> $Error[0].InvocationInfo

MyCommand             :
BoundParameters       : {}
UnboundArguments      : {}
ScriptLineNumber      : 3
OffsetInLine          : 7
HistoryId             : 36
ScriptName            : C:\Temp\test.ps1
Line                  :     $B = Get-ChildItem2 C:\temp

PositionMessage       : At C:\Temp\test.ps1:3 char:7
                        +     $B = Get-ChildItem2 C:\temp
                        +          ~~~~~~~~~~~~~~
PSScriptRoot          : C:\Temp
PSCommandPath         : C:\Temp\test.ps1
InvocationName        : Get-ChildItem2
PipelineLength        : 0
PipelinePosition      : 0
ExpectingInput        : False
CommandOrigin         : Internal
DisplayScriptPosition :


At this point, we could come up with a mildly complex function to recreate the initial output by referencing the appropriate properties. However, there's an easier way to get the error output.


Out-String


In all my years of PowerShell-ing, I've never had a reason to use Out-String, as most items will normally render as a string to the console or a file (as was evidenced above). Out-String does exactly what we want in this instance.
PS C:\Temp> $Error[0] | Out-String
Get-ChildItem2 : The term 'Get-ChildItem2' is not recognized as the name of a cmdlet, function, script file, or
operable program. Check the spelling of the name, or if a path was included, verify that the path is correct and try
again.
At C:\Temp\test.ps1:3 char:7
+     $B = Get-ChildItem2 C:\temp
+          ~~~~~~~~~~~~~~
    + CategoryInfo          : ObjectNotFound: (Get-ChildItem2:String) [], CommandNotFoundException
    + FullyQualifiedErrorId : CommandNotFoundException


From the console, this output is unsurprisingly identical to the statement $Error[0] issued all by itself.


We can add this into our script as follows:
(get-date -UFormat "%Y%m%d%H%M%S") + ": " + ($Error[0] | Out-String) | Out-File -filepath c:\temp\test.log
And finally our log file contains the full content we want:
20151209132608: Get-ChildItem2 : The term 'Get-ChildItem2' is not recognized as the name of a cmdlet, function, script file, or
operable program. Check the spelling of the name, or if a path was included, verify that the path is correct and try
again.
At C:\Temp\test.ps1:3 char:7
+     $B = Get-ChildItem2 C:\temp
+          ~~~~~~~~~~~~~~
    + CategoryInfo          : ObjectNotFound: (Get-ChildItem2:String) [], CommandNotFoundException
    + FullyQualifiedErrorId : CommandNotFoundException





Thursday, May 28, 2015

Deploy IIS URL Rewrite rules using PowerShell

I'm finalizing a FIM implementation that uses the FIM portal.  I have some fit-and-finish changes about the URLs I want to implement so that users who type in the site name automatically get to the HTTPS version of the FIM portal, rather than the HTTP version of SharePoint that lives at the root of the website.


It took a little while to figure out the syntax of the rewrites and how to deploy via PowerShell.  Most of the examples I found only provided the XML definition of the rule. Here are those two rules, ready for deployment via PowerShell (using the IIS PowerShell Snap-In).


Example: Redirect to HTTPS
$SiteName = "FIMSite"
$RuleName = "HTTP to HTTPS"
$Rule = @{
 Name = $RuleName
 patternSyntax = 'ECMAScript'
 stopProcessing = 'True'
 match = @{
  url = '(.*)'
  ignoreCase = 'True'
  negate = 'False'
 }
 conditions = @{
  logicalGrouping = 'MatchAll'
  trackAllCaptures = 'True'
 }
 action = @{
  type = 'Redirect'
  url = 'https://{HTTP_HOST}/{R:1}'
  appendQueryString = 'False'
  redirectType = 'Permanent'
 }
}
Add-WebConfigurationProperty -PSPath "IIS:\Sites\$SiteName" -Filter "/system.webServer/rewrite/rules" -Name "." -Value $Rule
$match = @{
 input = '{HTTPS}'
 matchType = 'Pattern'
 pattern = 'off'
 ignoreCase = 'True'
 negate = 'False'
}
Add-WebConfigurationProperty -PSPath "IIS:\Sites\$SiteName" -Filter "/system.webServer/rewrite/rules/rule[@Name='$RuleName']/conditions" -Name "." -Value $match


Example: Redirect to Application
$SiteName = "FIMSite"
$RuleName = "Redirect to FIM Application"
$Rule = @{
 Name = $RuleName
 patternSyntax = 'ECMAScript'
 stopProcessing = 'True'
 match = @{
  url = '^$'
  ignoreCase = 'True'
  negate = 'False'
 }
 action = @{
  type = 'Redirect'
  url = '/IdentityManagement/default.aspx'
  appendQueryString = 'False'
  redirectType = 'Permanent'
 }
}
Add-WebConfigurationProperty -PSPath "IIS:\Sites\$SiteName" -Filter "/system.webServer/rewrite/rules" -Name "." -Value $Rule