In our “Getting Started with Logging” series, we’ve already covered logging for many languages and frameworks: C#, Java, Python, Ruby, Ruby on Rails, Node.js, Symfony, Kotlin, Flask, Angular, and Laravel. Today, we’ll add another one to this series: PowerShell.

It might be an odd one to add to the list; PowerShell is a scripting language, while the others can be seen as full application programming languages or frameworks. Yet PowerShell is so sufficiently powerful that it can create systems complex and important enough to warrant logging.

PowerShell is often used to perform critical maintenance tasks on computers or servers. It’s important for admins to know how if these scripts ran well or not.

We’ll look into how you can log with PowerShell in a very basic way by writing your own logging function. Then we’ll cover why logging from PowerShell is useful. We’ll also talk about what you should log and what you should not log. Finally, we’ll look at two different options that will make your logging lives easier.

Powershell angle bracket and underscore with scalyr logo signifying powershell logging

A Simple PowerShell Script

Let’s start with this extremely simple PowerShell script:

param (
    [Parameter(Mandatory=$true)][int]$number
)

$digits = $number.ToString().ToCharArray()
$sum = 0

While ($digits.Length -ne 1) {
    $sum = 0
    $digits | ForEach { $sum += [int]$_.ToString() }
    $digits = $sum.ToString().ToCharArray()
}

Write-Output $digits

This basic script takes an integer as input. It then makes the sum of the digits of that number. If the result is longer than a single digit, it performs the operation again, until this results in a single digit.

Here are some examples to clarify things:

  • 45 -> 4 + 5 = 9
  • 397 -> 3 + 9 + 7 = 19 -> 1 + 9 = 10 -> 1 + 0 = 1
  • 3 -> 3

Put this script in a text file and save it as recursiveSum.ps1. Then, you can run it at the PowerShell command line by running recursiveSum.ps1 45, for example. The output will be 9:

This is a script that is simple enough to function as an example but has enough steps that we could be interested in some logging. Of course, real-life PowerShell scripts will be much more complex, warranting the need for logging even more.

The Easiest Way to Log in PowerShell

Let’s write the result of each step to the console. We’re already writing something to the console by using the Write-Output statement, so we can easily use that again. Change the While loop to include such a statement:

While ($digits.Length -ne 1) {
    $sum = 0
    $digits | ForEach { $sum += [int]$_.ToString() }
    $digits = $sum.ToString().ToCharArray()
    Write-Output "Intermediate result: $($sum)"
}

When you run it now, you should be able to see an output like this:

That’s great! We have some logging going on. However, these log statements will always be visible. In a more complex program, it might make sense to show nothing unless the user wants to see the logging. It’s probably also useful to give the user some control over the amount of detail they see. This is where log levels come in.

Log Levels in PowerShell

PowerShell has some Write-* statements that map to traditional log levels like:

  • Write-Verbose
  • Write-Debug
  • Write-Information
  • Write-Warning
  • Write-Error

Verbose

Let’s look at Write-Verbose first. We can change our messages about the intermediate steps to use Write-Verbose. When we run our script now, we won’t see our intermediate steps:

But if we add the -Verbose flag, our logs appear once again:

Debug, Information, and Warning

The Debug, Information, and Warning log levels work a little different than we’re used to from traditional logging frameworks in other languages. Let’s add some extra statements first:

Write-Debug "This is a debug statement"
Write-Information "This is an info statement"
Write-Warning "This is a warning statement"

The Write-Debug will only be visible when you add the -Debug flag. It will also stop your script from running and ask for confirmation to continue. This is useful to run through your scripts step by step.

But you do have some control over whether or not to show warnings and information messages. The Write-Warning and Write-Information commands can be controlled by using the -WarningAction and -InformationAction flags. If we omit these flags, only the warning messages are shown:

If we want to show the information messages, we can do so by adding -InformationAction Continue flag:

And if we want to hide the warnings, we can use the -WarningAction SilentlyContinue option:

Error

Finally, let’s look at how Write-Error works. We can add such a statement to our script:

Write-Error "Something went wrong"

When this statement is executed, PowerShell will stop the execution of our script and write the error to the console, along with some details that might be useful:

What Is Application Logging?

Let’s now take a step away from our PowerShell script and look at what application logging is exactly. The first post in our series defined it well:

Application logging involves recording information about your application’s runtime behavior to a more persistent medium.

We’re already doing the first part: in other words, capturing information about our application’s runtime behavior. We’re showing the intermediate results of our process. But we’re not doing the second part. We’re not recording this information to a persistent medium. When we close our PowerShell session, we’ve lost this information. Let’s do that first.

Logging to a File

We’ll add this Log function to our script file:

Function Log {
    param(
        [Parameter(Mandatory=$true)][String]$msg
    )
    
    Add-Content log.txt $msg
}

It simply takes in a String and then adds it to a log.txt file.

Then we can change our log statement so that it no longer uses Write-Verbose but this Log function instead:

Log "Intermediate result: $($sum)"

Now we can run our script and it will create a file containing our intermediate steps:

But if we run our script multiple times, it will just be a long list of statements. We have no way of knowing when the lines were logged. In a more complex scenario, containing multiple scripts, we also have no way of know where the log line originated—i.e., from which ps1 file. There’s more information that we could be logging.

Again, let’s take a step back and look at what we are trying to achieve with logging.

Why Do We Log?

PowerShell is often used to automate and script certain tasks that would otherwise be tedious and error-prone. Automation really starts to provide value when it is applied to more complex tasks. But these complex scripts might also have more chance of breaking: services may not respond, machine configurations may have changed, etc.

Without logging, it’s hard to know if scripts ran fine or if something went wrong. If something went wrong, logging will help us find out where and why it did. Application logging can also help you gather insights into which pieces of your scripts are being used most or where performance gains can still be made.

What to Log and What Not to: A Quick Detour Into Best Practices

Covering best practices at length would be out of the scope for this post. For starters, this post is but a basic introduction to logging. Also, we already have other posts dedicated to general logging best practices, such as the following ones:

However, we will cover two important aspects of logging best practices: namely, what you should and shouldn’t log. Even though when it comes to logging, the more the better, generally speaking, there are certain types of data you certainly must not log.

What Shouldn’t You Log?

When you write your logging statements, make sure you leave out sensitive or personal data. Examples include:

  • passwords and access tokens
  • credit card numbers or bank account numbers
  • social security numbers
  • email addresses
  • street addresses
  • encryption keys
  • social security numbers

The OWASP cheat sheet on logging has a section about data to exclude that is interesting to read. Although it is aimed at full-fledged applications, it could be useful for PowerShell scripts too. I can imagine scenario’s where PowerShell scripts handle email addresses or certain API keys.

Logging such personally identifiable information (or PII) is dangerous. Not only do you need explicit consent from the user in most countries, due to GDPR and other similar regulations, but if the data is ever leaked, you or your company could be held accountable. If it’s not really necessary, it’s better to leave this data out.

What Should You Log?

Our article on getting started with Ruby logging makes a great point:

You should think of a log entry as an event—something that’s of interest to your app that happened at some time.

This means that at a minimum, we need a timestamp and a description of the event. The description could also include relevant data. This is not always easy to determine upfront. Think about what you would need to troubleshoot a script that failed to run successfully. And if you later encounter a situation where you would have required more information to fix an issue, add it to the logging for next time.

Less obvious, but very useful, is to include a log level:

  • At the lowest level, Debug statements can be useful to track the executed flow of your PowerShell script.
  • A level up are Informational messages about the functional side of your script: what was executed, why, and with what data?
  • Then there’s also the level of Warnings: things that aren’t normal and potentially damaging but that don’t prevent the script from continuing.
  • Finally, Error-level messages are there to log errors that have made the script crash.

You can choose to log all these levels or only a specific level and up (for example, warnings and errors). Then, when you need more information, you can configure your script to also log more details on the next execution.

Our own simple logging function didn’t include log levels. Neither did it add a timestamp. We could add this functionality of course, but luckily others have already created decent logging scripts.

Enter the Logging Script

There is a simple yet useful script on Technet called Write-Log. If we download it, we can change our script to look like this:

param (
    [Parameter(Mandatory=$true)][int]$number
)

. C:\Users\peter\Function-Write-Log.ps1

$logPath = "C:\Users\peter\log.txt"
$digits = $number.ToString().ToCharArray()
$sum = 0

While ($digits.Length -ne 1) {
    $sum = 0
    $digits | ForEach { $sum += [int]$_.ToString() }
    $digits = $sum.ToString().ToCharArray()
    Write-Log -Message "Intermediate result: $($sum)" -Level Info -Path $logPath
}

Write-Output $digits

We’ve included the Function-Write-Log.ps1 file, removed our Log function, and replaced the call with a call to Write-Log. We can pass in a message, a level, and a path. The level can be Info, Warn, or Error. Notice that this script doesn’t have a Debug level, which is unfortunate. You could, however, easily modify it to include it, since the script is released under the MIT license allowing modification.

When we use this script, our log will look like this:

2021-07-22 09:18:29 INFO: Intermediate result: 51
2021-07-22 09:18:29 INFO: Intermediate result: 6

We now have clear log lines that include a timestamp, the log level, and our message. That’s much better than what we had previously. This may be sufficient for your needs, but let’s take it one step further and look at another option: the PSFramework.

Enter the Logging Framework

The PSFramework is a PowerShell framework that includes several useful utilities. 

PSFramework Core Concepts

Before diving into a hands-on demonstration of PSFramework, let’s take a step back and talk about some of the main concepts of the framework.

Message

A message is what is generated by your code and you want to log. Generally speaking, the message represents some relevant event you consider valuable to record.

Providers

Logging providers are one of the most important concepts in PSFramework. If you have experience with logging in other languages and logging tools, you might be familiar with the same concept under different names:

  • Appenders
  • Writers
  • Targets

These are just to name a few. They’re all the same: they represent possible destinations for your log messages.

In practical terms, you can think of PSFramework logging providers as plugins that know how to handle messages. A basic provider would be one that allows you to log to the filesystem. On the other hand, you could use a provider that allows you to log to Azure Log Analytics, for instance.

Providers Instances

In order to use a given provider, you’ll need a provider instance, which is a prepared “copy” of said provider—not that different from an instance of a class, in object-oriented programming.

Depending on your provider, you can have more than one instance alive simultaneously.

Installing PSFramework

To get started with the PSFramework, you will first need to install it by running Install-Module PSFramework in PowerShell. (You might have to run your PowerShell console as administrator). Then, you can write to the log files by calling the Write-PSFMessage script. In our case, it would look like this:

Write-PSFMessage -Level Output -Message "Intermediate result: $($sum)"

Notice how we’re not using an Info level. Instead, we’re using Output. This is because PSFramework uses log levels that match more nicely with that different output streams that PowerShell has by default: Verbose, Host, Output, Warning, Error, etc.

The log file will also look slightly different than what we’re used to:

"XPS-13-2021","22/07/2021 09:31:07","Output","Intermediate result: 28","Information, Debug","recursiveSum.ps1","<Unknown>","C:\Users\peter\recursiveSum.ps1","29","","","c00b36b8-76bc-4251-9549-0f541742236f"
"XPS-13-2021","22/07/2021 09:31:07","Output","Intermediate result: 10","Information, Debug","recursiveSum.ps1","<Unknown>","C:\Users\peter\recursiveSum.ps1","29","","","c00b36b8-76bc-4251-9549-0f541742236f"
"XPS-13-2021","22/07/2021 09:31:08","Output","Intermediate result: 1","Information, Debug","recursiveSum.ps1","<Unknown>","C:\Users\peter\recursiveSum.ps1","29","","","c00b36b8-76bc-4251-9549-0f541742236f"

The column headers are missing, but that can easily be remedied by setting the logging provider first:

$logFile = Join-Path -path "C:\Users\peter" -ChildPath "log-$(Get-date -f 'yyyyMMddHHmmss').txt";
Set-PSFLoggingProvider -Name logfile -FilePath $logFile -Enabled $true;

This log file will include a timestamp in the filename, and will now include a header row. This is because PSFramework’s default log provider will not add a header row, but the logfile provider will. The log file will now look like this:

"ComputerName","File","FunctionName","Level","Line","Message","ModuleName","Runspace","Tags","TargetObject","Timestamp","Type","Username"
"XPS-13-2021","C:\Users\peter\recursiveSum.ps1","recursiveSum.ps1","Output","32","Intermediate result: 28","<Unknown>","c00b36b8-76bc-4251-9549-0f541742236f","",,"22/07/2021 09:43:05","Information, Debug","XPS-13-2021\peter"
"XPS-13-2021","C:\Users\peter\recursiveSum.ps1","recursiveSum.ps1","Output","32","Intermediate result: 10","<Unknown>","c00b36b8-76bc-4251-9549-0f541742236f","",,"22/07/2021 09:43:05","Information, Debug","XPS-13-2021\peter"
"XPS-13-2021","C:\Users\peter\recursiveSum.ps1","recursiveSum.ps1","Output","32","Intermediate result: 1","<Unknown>","c00b36b8-76bc-4251-9549-0f541742236f","",,"22/07/2021 09:43:05","Information, Debug","XPS-13-2021\peter"

This now includes a lot of useful information like the filename of our script, the line where the logging occurred and the username of the user that is running the script. Another great advantage of the logging by PSFramework is that it logs asynchronously. The logging will not slow down your scripts. Finally, it will also automatically clean up your logs. By default, it will remove log files after seven days or when they exceed 100 megabytes.

A Comparison

The Function-Write-Log script matches more with what many application programmers are used to. It includes the standard log levels (except for Debug) and writes a log file like many logging frameworks do: a timestamp, the log level, and the message.

However, it misses some extra functionality that might be crucial to you: log clean up; asynchronous logging; and extra technical information like the script, line number, and executing user.

The PSFramework logging does provide these features, though it requires you to install the entire framework. This shouldn’t be a real issue, but it’s something to keep in mind. The PSFramework also uses different logging levels than we’re used to. However, they match closely to the PowerShell output streams. This may feel more natural to seasoned PowerShell users.

Summary and Next Steps

We’ve taken a look at a simple way to log in PowerShell. We also improved upon our own solution by using a better script (Function-Write-Log.ps1) and by using the logging included in PSFramework.

One thing that struck me was that logging in PowerShell is still fairly basic. It’s not that the options we looked at are bad or lacking. But I didn’t find a single logging script or module that includes multiple log levels, asynchronous logging, log clean up, and, most importantly, multiple log destinations.

What if we want to send errors to an email address? Or what if we want to log to a database? As far as I can see, PSFramework offers the most options here, but email or database aren’t included. It might be possible to write your own and register it in PSFramework, though.

This might be because the world of PowerShell is different that the world of application development. PowerShell scripts may be much more custom-made, meant for a specific scenario, and composed of multiple separate scripts.

Yet logging remains important, especially with scripts that run regularly and have a certain level of complexity. PowerShell is a powerful language to automate a multitude of tasks. When something goes wrong with such a task, you want to know what went wrong, what preceded it, and how to fix it. Logs give you this information.

Log Smarter and Stop Putting Out Fires!

Do you know what’s the biggest tragedy of logging is? It’s the fact that most organizations treat it as a mere troubleshooting mechanism.

Sure, logging is invaluable for understanding and fixing issues, there’s no denying that. Using the data from your log files to make your debugging and post-morten sessions easier is certainly way better than the alternative, which would be going blind.

But what if I told you that logging can be used not only to fix issues but even to prevent them altogether? What if I told you that’s possible to quit putting out fires and start stopping them from beginning?

That’s exactly the value proposition of log management. Log management is the process of collecting your logs, then extracting useful data from them. If that sounds underwhelming, here’s a list of only a few of the use cases for log management:

  • You can set up real time alerts and notifications. A great log management tool can analyze data from your logs, identify concerning trends, and then proactively notify the key people.
  • You get dashboards to visualize your environments in real time.
  • You get super fast search among log entries from your entire organization.

To sum it up, not using log management is pure waste. You have a treasure in the form of all the data inside your logs, and you doing a whole lot of nothing with it.

To leverage log management, you’ll need a tool, and Scalyr is a great one for this. Have look at the Scalyr API for the different options of sending log events to Scalyr. This can easily be called from PowerShell and will improve your ability of monitoring and troubleshooting your PowerShell scripts.