A better logging method

Recently, I was asked to make some changes to lots of users in Active Directory. For output, they wanted a log of everything that was changed and a log of where changes failed. Of course, I wanted a third log with verbose output of everything that was happening so, if need be, I could go back and fix anything.

Another thing I wanted to do was not write 5 times a second. Rather than slow down the process of making changes to users, I wanted to collect strings for the logs and write out every time I collected X number of strings.

To do this, I created a new Type using C# code. I’ve been reading Windows PowerShell for Developers (Dougals Finke) which has been an eye-opener to say the least.

Here is the code I came up with…

Add-type -TypeDefinition @"
using System.Collections;
public class Logger {
	public System.Collections.ArrayList Entries;
	public int    Count;
	public int    MaxLines;
	public string LogFile;

	public Logger(){
		Entries = new System.Collections.ArrayList();
		Count = 0;
		MaxLines = 5;
		LogFile = "";
	}

	public void Add(string str)
	{
		Entries.Add(str);
		Count++;
		if (Count >= MaxLines)
		{
			AppendLog();
		}
	}

	private void AppendLog()
	{
		if (! ([string]::isNullOrEmpty(LogFile)) )
		{
			using (System.IO.StreamWriter file = new System.IO.StreamWriter(LogFile, true))
			{
				foreach (string entry in Entries)
				{
					file.WriteLine(entry);
				}
			}
			Entries.Clear();
			Count = 0;
		}
	}

	public void Flush()
	{
		AppendLog();
	}

	public void setLogFile(string file)
	{
		LogFile = file;
	}

	public void setMaxLines(int max)
	{
		MaxLines = max;
	}
}
"@

This type compiles a “Logger” object which has a few properties and a few methods.

Logger Properties

TypeNameDescription
Intcountthe count of strings currently collected
IntMaxLinesNumber of lines (strings) to collect before being forced to write to the file.
StingLogFilethe logfile to write to (including path).

Logger Methods

NameDescription
Logger (Constructor)Sets default values for the object
AddAdds a string to the object. All strings will be stored until either a “flush” command is called or the ‘maxLines’ limit is reached.
AppendLogAppends the collection of strings to the specified log file
FlushWrites all currently collected strings to the log file.
SetLogFileSets the logfile to be written to.
SetMaxLinesSets the maximum number of lines to store until being forced to write to the log file.

Example usage

PS C:\> $logger = new-object logger
PS C:\> $logger |ft -auto

Entries Count MaxLines LogFile
------- ----- -------- -------
{}          0        5


PS C:\> $logger.setMaxLines(10)
PS C:\> $logger |ft -auto

Entries Count MaxLines LogFile
------- ----- -------- -------
{}          0       10


PS C:\> (1..9) |% { $logger.Add("$_") }
PS C:\> $logger |ft -auto

Entries         Count MaxLines LogFile
-------         ----- -------- -------
{1, 2, 3, 4...}     9       10


PS C:\> $logger.setLogFile("C:\temp\log02.log")
PS C:\> $logger.Add("end")
PS C:\> $logger |ft -auto

Entries Count MaxLines LogFile
------- ----- -------- -------
{}          0       10 C:\temp\log02.log


PS C:\> gc $logger.LogFile
1
2
3
4
5
6
7
8
9
end
PS C:\>

Results

As a result of this, I was able to add this type to the script I was creating and create 3 logger objects:

# Debug logging
$logVerbose = new-object Logger
$logVerbose.setMaxLines(10)
$logVerbose.setLogFile("$pwd\Verbose.log")

# Change logging
$logChanges = new-object Logger
$logChanges.setMaxLines(5)
$logChanges.setLogFile("$pwd\Changes.log")

# Failed changes logging
$logFailedChanges = new-object Logger
$logFailedChanges.setMaxLines(5)
$logFailedChanges.setLogFile("$pwd\FailedChanges.log")

Logging to any one log was easy, just use the example above. If I wanted to log to all the logs, like setting the start point for the running of the script I would do something like this:

$commonLogString = (& $logPrefix ) + ""
$commonLogString += (& $logPrefix ) + "***********************`r`n"
$commonLogString += (& $logPrefix ) + "SCRIPT START`r`n"
$commonLogString += (& $logPrefix ) + "***********************`r`n"
$commonLogString += (& $logPrefix ) + "`r`n"
$commonLogString += (& $logPrefix ) + "Script Options:`r`n"
$commonLogString += (& $logPrefix ) + "-----------------------`r`n"
$commonLogString += (& $logPrefix ) + "Option 1: $Opt1`r`n"
$commonLogString += (& $logPrefix ) + "Option 2: $Opt2`r`n"
$commonLogString += (& $logPrefix ) + "Option 3: $Opt3`r`n"
$commonLogString += (& $logPrefix ) + "-----------------------`r`n"
#$commonLogString += (& $logPrefix ) + "`r`n"

$logVerbose.Add($commonLogString)
$logChanges.Add($commonLogString)
$logFailedChanges.Add($commonLogString)

The $logPrefix was a scriptblock I specified earlier on as

$logPrefix = {get-date -format "[ MM/dd/yy HH:mm:ss ] "}

This way each line would have a date/time header.

Leave a Reply