.NET, Software Development

Logging in C#: enumerations, thread-safe StreamWriter

6 Comments

Joe gave me some great feedback on the C# logging utility I wrote about a couple months ago. Per his suggestions, I modified it in the following ways:

1) Instead of using public static int variables as levels, I added an enumeration:

enum Priority : int {
  OFF = 200,
  DEBUG = 100,
  INFO = 75,
  WARN = 50,
  ERROR = 25,
  FATAL = 0
}

An enumeration is a value type (ie: the enumeration is not a full fledged object) and thus is allocated on the stack. I’m guessing that Joe suggested the use of an enumeration for 2 reasons. First, an enumeration groups the constants together… in some sense it encapsulates what was a group of unrelated static integers into a single type, in this case named ‘Priority’. Second, because enumerations are value types (and thus are allocated on the stack), they require less resources from both the processor and memory on which the application is running.

2) Joe mentioned “… you probably need to put a lock{} around the calls to it (StreamWriter) –it’s not guaranteed to be threadsafe.“. Turns out he’s right (not that it was a surprise). The StreamWriter documentation has this to say: “Any public static (Shared in Visual Basic) members of this type are thread safe. Any instance members are not guaranteed to be thread safe.” But the solution is easier than putting a lock{} on it. StreamWriter extends the TextWriter class, which itself has a static method for generating a thread safe wrapper. So where in the first version I had this:

StreamWriter sw = File.AppendText(filePath);

I now have this:

TextWriter tw = TextWriter.Synchronized(File.AppendText(filePath));

The File.AppendText() method returns a StreamWriter object, which the TextWriter.Synchronized() method wraps to create a thread-safe TextWriter which can be used just like a StreamWriter.

3) I noticed that the log4j implementation uses wrapper methods to make the argument list shorter. For instance, the Logger class has methods that look like this:

public void debug(Object message);
public void info(Object message);
public void warn(Object message);
public void error(Object message);
public void fatal(Object message);

I added the same idiom to my Logger class:

public static void Debug(String message) {
  Logger.Append(message, (int)Priority.DEBUG);
}

while still allowing for the more verbose:

public static void Append(String message, int level)

I uploaded the source and a test so you all can have a hack at it, if that kind of thing toots your horn:
· Logger.cs
· TestLogger.cs
I’m *always* open to comments and feedback. If you have even an inkling as to what I could do better with this code, *please* add your thoughts below.

6 thoughts on “Logging in C#: enumerations, thread-safe StreamWriter”

  1. Hey AJ,

    Actually, I meant an enum might be useful as a way of providing a *complete* set of log levels–i.e. you can only use the levels provided in the enum, no others. If you want to preserve the granularity that ints give you, you’re better off using “public const” ints as you said originally. Enums give you type safety by making the compiler aware of the universe of possible values–you can prevent -100 from being passed in where “day of the week” is expected, for example. But if you mix enums and ints, then you essentially defeat the purpose of enums. One clue is anytime you are casting an enum value to another data type, there’s a good chance you don’t want to use an enum at all. Sorry for the confusion.

    I think it’s really important that you create the TextWriter just once, and keep it around–use a static initializer for this, probably. Very important for performance.

    Also, the TextWriter.Synchronized trick is really nice–I wasn’t aware of it–but in this case I think you still need a lock. Either that or combine your multiple tw.Write(Line)’s into a single tw.WriteLine call. Otherwise it’s possible for multiple log entries to collide. The Synchronized wrapper will prevent two simultaneous calls to the TextWriter from corrupting the internal state of the TextWriter, but it won’t prevent multiple lines that are part of a single log entry from being broken up by the lines of a log entry on another thread. And anyway, using a single lock statement will actually be faster than using TextWriter.Synchronized, since right now inside that try/catch block you’re probably making TextWriter acquire and release a lock 5-7 times (one for each method call). You can cut that down to one by calling lock{} yourself and leaving the writer itself unsynchronized.

    (Actually with your current implementation you don’t have that problem, since your TextWriter is never shared between threads–so right now you don’t even need synchronization at all. But if you follow my advice and keep around the TextWriter, then you will need to synchronize/lock.)

    LMK if this is all clear…

    -joe

  2. Hi Joe,
    some intereting comments. however i’ve been struggling to do as you suggested and keep the TextWriter around.

    I want to basically create the file once, open it and then just append to this TextWriter for the lifecycle of the logger class. When the logger disposes it should cleanup and release the TextWriter.

    any chance you posting your version of Logger.cs with this implemented ?

  3. hi Ryan,

    Joe and I talked about this in detail. Two things:

    a) rather than using TextWriter.Synchronized(), use a StreamWriter with a lock{}.

    and b) to keep the StreamWriter around, make it a class (rather than local or instance) variable. I updated both Logger.cs and TestLogger.cs.

  4. Works for me! Thanks!

    If you change the line:
    int logLevel = (int)Priority.OFF;
    to:
    Priority logLevel = Priority.OFF;

    you don’t have to do the casts all the time, and casts are expensive operations (I don’t know if the framework does it anyway :))

    Don’t I ever have to Close the stream?

  5. I like the integer constants route on log messages. It gives more flexibility in filering of log messages. It also opens up the possiblity that there are more severity levels than you define in your enum. If you want to output a level name “closest” to the enum, you can do that with a switch inside a static method…

    public struct Priority
    {
    public const int Error=256;
    public const int Warning=512;
    //add more level constants
    public static string GetName(int level)
    {
    if (level <= Error)
    return “Error”;
    else
    return “Warning”;
    //add more else ifs
    }
    }

    I was using an enum until I saw this article, and then I looked into the performace implications of using an enum. I’ll be releasing a new version of my logging component soon.

    http://sourceforge.net/projects/xqs-logging/

    You can comment on my logging component here:
    http://groups.msn.com/XQuiSoft/xqslogginghelp.msnw

    Michael Lang
    XQuiSoft LLC

Comments are closed.