If you regularly download or look at the functions and scripts I post here, you'll notice I often use Write-Verbose to indicate what is happening. This comes in handy for troubleshooting. But often it would also be helpful to record as a log file of script activity. Unfortunately, you can't pipe Write-Verbose to Out-File. So I came up with my own function called Write-Log that gives me the best of both worlds. I can get verbose messages and send those messages to a text file for logging.
ManageEngine ADManager Plus - Download Free Trial
Exclusive offer on ADManager Plus for US and UK regions. Claim now!
The function is relatively simple. This is the core code without the comment based help.
Function Write-Log {
[cmdletbinding()]
Param(
[Parameter(Position=0)]
[ValidateNotNullOrEmpty()]
[string]$Message,
[Parameter(Position=1)]
[string]$Path="$env:temp\PowerShellLog.txt"
)
#Pass on the message to Write-Verbose if -Verbose was detected
Write-Verbose $Message
#only write to the log file if the $LoggingPreference variable is set to Continue
if ($LoggingPreference -eq "Continue")
{
#if a $loggingFilePreference variable is found in the scope
#hierarchy then use that value for the file, otherwise use the default
#$path
if ($loggingFilePreference)
{
$LogFile=$loggingFilePreference
}
else
{
$LogFile=$Path
}
Write-Output "$(Get-Date) $Message" | Out-File -FilePath $LogFile -Append
}
} #end function
The function takes two parameters, -Message and -Path. The former is the string of text you want to display and/or log to a text file. The Path is the filename and path of the log file. I've given this parameter a default value of $env:temp\PowerShellLog.txt. The function writes the message string to the log file with the current date and time prepended.
Write-Output "$(Get-Date) $Message" | Out-File -FilePath $LogFile -Append
Output is always appended to the log file. Because the function uses cmdlet binding, if it detects -Verbose then the Write-Verbose message will be visible.
#Pass on the message to Write-Verbose if -Verbose was detected Write-Verbose -Message $Message
Now here's the fun part. I wanted to make Write-Log to behave like Write-Verbose. That is, I wanted to include the command in my scripts and functions but only have it actually do something when I needed it. My Write-Log function looks for two variables. The first is $LoggingPreference. If this has a value of "Continue", then logging takes place. I also reference another variable called $loggingFilePreference. This variable contains the filename and path for your log file and takes precedence over the temp file default.
#only write to the log file if the $LoggingPreference variable is set to Continue
if ($LoggingPreference -eq "Continue")
{
#if a $loggingFilePreference variable is found in the scope
#hierarchy then use that value for the file, otherwise use the default
#$path
if ($loggingFilePreference)
{
$LogFile=$loggingFilePreference
}
else
{
$LogFile=$Path
}
Write-Output "$(Get-Date) $Message" | Out-File -FilePath $LogFile -Append
}
There are several ways then that you could use this. First off, you need to dot source the function either in your PowerShell session or your script/function. Within your code use Write-Log just like you would Write-Verbose. To "activate", all you need to do is set $LoggingPreference to "Continue" somewhere. Here's one example.
Function TryMe {
[cmdletbinding()]
Param([string]$computername=$env:computername,
[string]$Log
)
if ($log)
{
$loggingPreference="Continue"
$loggingFilePreference=$log
}
Write-log "Starting Command"
Write-log "Connecting to $computername"
$b= get-wmiobject -class win32_bios -ComputerName $computername
$b
Write-log $b.version
Write-Log "finished" $log
}
PS C:\> TryMe -log e:\logs\sample.txt -verbose
My TryMe function includes a parameter called -Log. If I use this parameter, then the logging variables are set and my Write-Log commands will work. If I don't use -Log, Write-Log is still called but nothing is written. Because TryMe uses cmdlet binding, if I run it with -Verbose then I'll get the verbose message via Write-Log. You can even use both -Verbose and -Log which will give you verbose messages and write to the log file.
Another way would be to turn on the logging variable and use the default log. Here's a snippet.
Function Test-Foo {
[cmdletBinding()]
Param([string]$name,
[switch]$Logging
)
if ($Logging)
{
$loggingPreference="Continue"
}
Write-Log "Starting Test-Foo"
...
}
This gives me the -Logging parameter that turns everything on. Remember, in this snippet the log file will the default in the TEMP folder. Although as an added bonus because you can specify a log file, you can write to multiple log files within the same script or function.
I hope you'll let me know what you think and if you find this useful. If so, don't forget my tip jar.
Download Write-Log.ps1.
Thanks, Jeffery. I’ve looked for a logging solution that fits the PowerShell “idiom”, but haven’t found (or written) such a critter. This is pretty close to what I was thinking of.
I hope you’ll let me know how it works out in a real production setting.
I’ve been looking for a logging solution for Powershell scripts for a long time. I’d like to write status information to screen AND to a log file at the same time with the least amount of code possible (1 line).
Something like this would be great,
Write-Error -Message “woops” | Tee-Object -FilePath $env:TEMP\woops.txt
Write-Warning “woops” | Tee-Object -FilePath $env:TEMP\woops.txt
This doesn’t work however because these don’t have any output.
My Write-Log function should give you exactly that result. Make sure your script uses cmdletbinding and then specify -Verbose.
I’m not a big fan of verbose though because it doesn’t inform the user whether and error has occurred or just something for informational purposes. The nice thing about Write-Error is the output looks like an error, the same with Write-Warning (looks like just a warning). I wish I could use Tee-Object just to send the output of Write-Error, Write-Warning and Write-Host to screen and file at the same time.
I’d update your function to support log level instead of using verbose to look something like this:
function Write-Log {
[cmdletbinding()]
Param(
[Parameter(Position=0)] [ValidateNotNullOrEmpty()]
[string] $Message,
[Parameter(Position=1)] [ValidateSet(“Error”, “Warn”, “Info”)]
[string] $Level = “Info”,
[Parameter(Position=2)]
[IO.FileInfo] $Path=”$env:temp\PowerShellLog.txt”
)
try {
if (-not $Path.Exists) {
$Path.Create()
$Path.Refresh()
}
$msg = “{0} : {1} : $Message” -f (Get-Date -Format “yyyy-MM-dd HH:mm:ss”), $Level.ToUpper()
switch ($Level) {
“Error” { Write-Error $Message }
“Warn” { Write-Warning $Message }
“Info” { Write-Host $Message }
}
$msg | Out-File -FilePath $Path -Append
} catch {
throw “Failed to create log entry in: ‘$Path’. The error was: ‘$_’.”
}
Write-Log -Message ‘It’s all good!’
.EXAMPLE
PS C:\> Write-Log -Message ‘Oops, not so good.’ -Level Error
.INPUTS
No pipeline input.
.OUTPUTS
No output.
#>
}
Write-Log -Message “hi”
Write-Log -Message “Watch out!” -Level Warn
Write-Log -Message “Crap!” -Level Error
& Notepad $env:temp\PowerShellLog.txt
That’s an interesting and useful approach, although not quite what I was going for. My primary purpose was to make it easier to have a simple log file of what is happening. Leveraging the verbose pipeline was a bonus. I wasn’t trying to redirect or capture the Verbose, or any other stream. The lack of an option to capture the error, verbose and other pipelines is well known and perhaps we’ll see new options in some future version of PowerShell. But I do like that you added code to make this even more flexible. That’s always a good thing.
The post sanitizer looks like it botched up my comment based help. It stripped out my .SYNOPSIS , .DESCRIPTION, .PARAMETER entries. It should look like this:
.SYNOPSIS
Writes logging information to screen and log file simultaneously.
.DESCRIPTION
Writes logging information to screen and log file simultaneously. Supports multiple log levels.
.PARAMETER Message
The message to be logged.
.PARAMETER Level
The type of message to be logged.
.PARAMETER Path
The log file path.
.EXAMPLE
PS C:\> Write-Log -Message ‘It’s all good!’
.EXAMPLE
PS C:\> Write-Log -Message ‘Oops, not so good.’ -Level Error
.INPUTS
No pipeline input.
.OUTPUTS
No output.
After thinking about it a bit I think it would be great for Microsoft to just add a -FilePath to the Write-* cmdlets (Write-Error, Write-Warning, Write-Debug, Write-Verbose).
I looked for some other logging solutions on Posh Code and the only one I found that looked helpful was this guy – http://poshcode.org/1858 . which actually replaces the Write-* cmdlets and uses log4net via a ton of code. That’ s way to complicated for something that I think should just be built in…
A lot of people would like that sort of feature and I hope we get it in some future release.
Your approach of hiding the logging – whatever the actual ‘logging’ is – behind a function instead of doing directly in the script is something I’ve been doing for awhile for a variety of reasons. One reason for *having* to do it this way: it gives you the ability to log inside functions that return values without messing up the content in the pipeline. As long as the log function writes directly to host and/or file – and not the pipeline – you’re good.
However, you can add lots of great functionality to your log function as well. I have a log level (similar to Andy’s), an optional indent level param (if you want to indent particular log entries, now there’s no need to put lots of spaces in the message) and support for pipeline input. Pipeline input really helps make your code succinct and readable: | Add-Log
In addition my log function has special support for different object types. That is, rather than accept a string as the main param, accept object and extract/prepare the text for logging based on the type. That’ll make it easier to log, say, exceptions with nested exceptions or error record objects (there’s lots of info on these heavy objects; select only the fields you want). Plus you can throw in some frills: for example, if my log function receives a hash table, it gets the hash table keys, sorts them then outputs the key/values based on the sorted key order.
Alas, the downside of all this is that once you start using it from within other functions or scripts you written, you are now dependent on it. As I’m currently rewriting all my PowerShell code as a module framework which will be on all our servers, this is good (awesome design / powerful / great re-usability) and bad (can’t share easily with folks outside the organization). One thing Microsoft could do with PowerShell 3 is provide a built-in Add-Log function that could be overridden, similar to prompt or tab expansion. That way you can always write script that calls Add-Log; if you don’t override the function the content goes to the host (certainly not the pipeline) but if you do override, it could also go to a file, an event log, log4net, null, wherever you want).
Here’s what I put together, check it out. I was inspired when you mentioned indention levels that sounded cool 🙂
http://poshcode.org/2566
Nice function – clean, simple and powerful! Good stuff.
I often get torn between writing concise functions or taking advantage of modules. Modules can be harder to share with others and use consistently but better for building & organizing common functionality. If you build a logging module you can initialize it at the beginning of your script with common settings – like log file path, event log name, etc. – and this keeps your individual Write-Log statements in the script much simpler. But then you’re locked into this code for all your future scripts and probably end up creating lots of inter-module dependencies. Oh well, typical analysis paralysis….
Actually, I think modules should be easier to share and keep you more organized. And modules are designed to be interdependent. You have to build the framework that meets your administrative needs.
Yeah my post was sanitized as well; the pipeline example input was supposed to be:
code that generates multiple items | Add-Log
I totally agree. The function can be as complex or feature-rich as you want it. The long term solution is support writing other PowerShell streams to a text file.
Keith, I just found you’re blog here:
http://rkeithhill.wordpress.com/2009/03/06/effective-powershell-item-14-capturing-all-output-from-a-script/
Key take away: Powershell community: Please vote these UP!
http://connect.microsoft.com/PowerShell/feedback/details/283088/script-logging-needs-to-be-improved
https://connect.microsoft.com/feedback/ViewFeedback.aspx?FeedbackID=297055&SiteID=99
Nothing to add to the logging function. But for viewing the log file I create this small functions to tail the output in an another screen. By default it will take the youngest file…
Function Tail-LastLog()
{
Param(
[Parameter(Position=0)]
[ValidateNotNullOrEmpty()]
[string]$LogFile=(ls $env:temp\Posh*.log | sort lastwritetime -desc)[0]
)
cat $LogFile -wait
}