#PSBlogWeek – Building Readable Text Log Files

This post is part of the #PSBlogWeek PowerShell blogging series. #PSBlogWeek is a regular event where anyone interested in writing great content about PowerShell is welcome to volunteer for. The purpose is to pool our collective PowerShell knowledge together over a 5-day period and write about a topic that anyone using PowerShell may benefit from. #PSBlogWeek is a Twitter hashtag so feel free to stay up to date on the topic on Twitter at the #PSBlogWeek hashtag. For more information on #PSBlogWeek or if you’d like to volunteer for future sessions, contact Adam Bertram (@adbertram) on Twitter.

Once you’re done getting schooled on everything this post has to offer head on over to the powershell.org announcement for links to the other four past and upcoming #PSBlogWeek articles this week!

The skilled PowerShellers who authored the previous PowerShell blog week introduced and developed the practice of advanced functions.

As you mature in your PowerShell skills from one-liners to scripts, advanced functions, and eventually modules, you may realize the need to log the activities you are performing with your tools. Logging your PowerShell scripts can be extremely important for tools that change settings or data so that you can audit who made changes and when.

Surprisingly, logging functionality isn’t a built-in PowerShell feature (yet) so we’re left with building our own logging tools. Hit up your favorite search engine, the TechNet Gallery, or the PowerShell Gallery, and you’ll find quite a few people who have built their own logging functions that may meet your needs.

I’m going to walk you through an advanced function that you can use to add logging to your scripts, but first, I want to show you how I got there.

When I first realized the need for logging in my scripts I started by using the Add-Content cmdlet, which I would sprinkle here and there in my scripts to capture key points in my operations.


Using Add-Content for logging
Using Add-Content for logging

When I realized that I was repeating too much code, I decided to create a helper function in my scripts to make it simpler for me.

(Very) Basic Write-Log Helper Function
(Very) Basic Write-Log Helper Function

Sample Log File:

It saved me a little work, and it looks a little cleaner. However, the log file is only lines of text without any specific information about when each action happened or how much time elapsed between actions. Let’s add a time stamp to our helper function.

Added formatted timestamp.
Added formatted timestamp.

Here’s the log:

Better right? We can do better. We should offer a way to differentiate the type of message we are writing to a log file. Sometimes we just have informational messages, but we also might have warning or error messages we would like to log. With our current log format, we can’t tell what is an error or simply informational without reading the log file message line by line. Let’s add a Level parameter.

Level parameter added.
Level parameter added.

Log File:

Now that’s starting to look like a decent log file that we can we can search through using grep Select-String.

Let’s promote this helper function to an advanced function, add some logic, and sanity checks so that we can have a versatile logging tool for our PowerShell toolbox.

Stepping through the code, we see our comment-based help for the “next guy” (including myself who tends to forget how my own code works after a few weeks).  Then, I added the magic keyword CmdletBinding to transform our lowly function into an advanced function with cmdlet superpowers. I attempt to use standard parameter names where applicable and use the ValidateSet attribute on the Level parameter to ensure the user enters a proper level.

The Begin block sets the VerbosePreference to Continue so that our Write-Verbose statements are sent to the Verbose pipeline.

The Process block starts by creating a new log file, including requisite path, ensuring that we don’t clobber (overwrite) the file when the NoClobber switch is present.

Based upon the selected Level, with Info being the default, we then write the message to our log file as well as send the supplied message to the Verbose, Warning, or Error pipeline where applicable.

That’s great, but how do I use this in my scripts? I’m glad you asked. After the function is loaded, either via dot-sourcing or added to a module, you can begin adding the Write-Log function to your scripts.


Write-Log Example
Write-Log Example

Sample Log:

Although this is just a basic example of how you could use Write-Log in your scripts, you can incorporate it in a way that works best for you. I found it helpful to include a header, footer, and log rotation as part of my template script.

Write-Log Template Function
Write-Log Template Function

PowerTip: Read more about setting default parameter values $PSDefaultParameterValues so that you don’t have to specify the Path every time you call the Write-Log function (#Requires -Version 3.0).

Here’s an example of a log generated from my Set-IPAddress function which shows the name of the script, where it was run, and who ran it (names were changed to protect the innocent).

Example Log Output:

If you think you can use this Write-Log function, feel free to download it and add it to your tool belt. If you see ways you could improve the script, feel free to send along your suggestions via Twitter or improve it yourself on github.  If you don’t like the script, feel free to download it anyway, and then you can have the pleasure of putting it in your Recycle Bin.

In summary, we find, at times, that our scripts, functions, and modules need some basic text logging, especially if the code is going to modify a system configuration or data. We walked through Write-Log, an advanced function that we can use to create readable text logs.

5 Replies to “#PSBlogWeek – Building Readable Text Log Files”

  1. The problem with this kind of logging is it only captures what you EXPECT to happen. Inevitably you will have an error in some place you just didn’t expect. Query to AD that comes back $null when your expectation is that it never would, then you call a method on the $null and boom error. But no Try/Catch so you don’t know what happened (this is a super rough example). Sure, you run the script manually a few times, figure out the problem add the Try/Catch code and you’re good to go, but valuable time has been wasted rerunning the script just to see the original error.

    I’ve fallen in love with Transcript logging. Simply Start-Transcript (with some code around the path name) and everything that happens in the script is captured in the log. Maybe not quite as pretty, but more complete.

  2. I love this blog post! I wish more content was written this way. It takes me from a one-liner and adding to it with explanations as to why, until we get to a finished script that addresses a common need. It started simple, became more complex, but in a way that I could follow most of it. Now I have a reference script to ask questions and learn more on my own… like what does ValueFromPipelineByPropertyName do? (for example)

    Thank you!

  3. Great post. I have been working on similar functionality, and will propably “borrow” some of your code 😉
    Right now I am working with three functions:
    1) New-ScriptLog where the logfile is initialized. Usually with a timestamp and user of the current script execution.
    2) Write-ScriptLog that looks a lot like your. The path is not a parameter, and usually I stream the log text to this function.
    3) Skip-Script is only used if I have to leave the planned script because of an error or other breaking deviation.
    I do not have your NoClobber parameter, but can see that it might be handy. Again I wil propably “borrow” from your code…

Leave a Reply

Your email address will not be published. Required fields are marked *