Contents
- Introduction
- Background
- Integration Into Your Project
- Using the SS_Log Class
- Creating Multiple Local Logs
- Using the Viewer (SS_Log_Server.exe)
- Creating Your Own Filters
- Create Your Own Destinations
The Complete class documentation can be found at http://sslog.webhop.net.
Introduction
Often times we want to create a log of what steps a program takes during run-time. Maybe our program works fine on all of our computers in house, but it is crashing at a customer's site. Or maybe we are developing on WinNT, but are testing on Win98 without a development environment on the Win98 machine. Since we can't debug in these cases, it would be nice to have a log of all the steps a program took before it crashed.
This set of projects perform program logging and offer numerous features:
- Easy integration into any project (MFC, Windows non-MFC, console). Just include "SS_Log.h".
- Log messages with sprintf-style functionality in a single line of code.
- Automatically include date/time, filename and line number info in every message.
- Log to multiple destinations, including to a file, to the NT Event Log, and/or to a dynamic viewer that launches on demand. Implement your own destination by deriving from a provided base class.
- Assign flags to messages, and filter out the undesired flags on the fly. Easily define your own message types and automatically have full viewer and filter functionality for your new types.
- Dynamically filter based on message flags, message text, message ID, etc. after program has completed.
- Double-click on messages in the provided viewer and Visual Studio will jump to the corresponding file and line number (currently supported in VC++ 6.0 only. VS.NET to come...).
- Log "Entering MyFunction" and "Exiting MyFunction" messages automatically with only 1 line of code (per function).
- Have multiple simultaneous logs, each with their own parameters and destinations.
- Entirely thread safe.
- Set a maximum file size that your log file should not exceed. The system will throw away the oldest messages and continue logging.
- VERY FAST! During testing on an AMD 1700+, I logged over 100,000 messages in under 10 seconds! While many logging systems will slow the performance of your app, this one shouldn't noticeably impact you.
Background
This is version 3 of the code. Version 3 has undergone a major re-write, and many of the functions that once were part of the SS_Log class have now been deprecated. All deprecated functions are still supported, so your older code should still work with this version, but for those who've use this code in the past, please make yourself familiar with the new calls.
In the first version of this code, if writing to a file, we would write and flush each message immediately when the message was logged. This caused a good bit of slowdown. The reason for the immediate flush was, if your program crashed, you'd be guaranteed to have all messages that were logged before the crash.
The new design still guarantees that all messages will be logged, but we won't force the overhead of flushing to file every time. Instead, all messages get sent to a server in a separate process that is launched and terminated on the fly, and the server will flush the contents out when it gets the chance.
I want to thank Graven for this suggestion. That and the "dynamically filter after the fact" suggestions are the basis of the new design, and they were his ideas. Several other people made suggestions too, and I appreciate all of them. I implemented many of them, and those that I did not, I will definitely keep on the list for the future.
Integration into your project
Integration into your project is easy. The following steps are necessary:
- #include "SS_Log.h" in any file that you want to log from.
- For debug builds, link against SS_LogD.lib, and for release builds, SS_Log.lib. If you would prefer to compile the cpp files instead of linking to the libraries, compile SS_Log.cpp and SS_Log_Defines.cpp.
- #declare "_SS_LOG_ACTIVE" in your project. DO NOT FORGET THIS STEP!
- Copy the SS_Log_Server.exe and SS_Log_AddIn.dll files into your %SYSTEMROOT% folder (ex. c:\winnt or c:\windows.).
That should about do it. The SS_Log code will handle the rest. If you downloaded the sources rather than the binaries, compile the projects in the following order:
- Utils -- just a set of helper classes (string, registry, and list). Feel free to use these classes in your projects... they are fairly robust ;-)
- SS_Log -- the main SS_Log logging class. The files in this project are the ones that you will include in your application to do your logging.
- SS_Log_Server -- the server and viewer project. This project will generate the SS_Log_Server.exe that must be copied into the %SYSTEMROOT% directory, and will receive all messages as they are generated by the SS_Log class.
- SS_Log_AddIn -- the Visual Studio addin. This project generates the SS_Log_AddIn.dll file that must be copied into the %SYSTEMROOT% directory. It Allows the user to double-click in the viewer and have Visual Studio jump to the corresponding file and line number.
- SS_Log_Test -- this is just an example of how to use the SS_Log class. There is extensive commenting in this project to give you an idea of much of the functionality of SS_Log.
To see how quick and easy it is to start logging, I give you the following code:
#include "SS_Log.h"
main()
{
Log("Hello World!");
}
... and as long as you've not forgotten to #define _SS_LOG_ACTIVE in your precompiler, this code will produce a log with the filename, line number, date/time, default filter, message ID, and your message text.
Using the SS_Log Class
Before reading this whole article (as it is quite long), you might want to just look in the sample program (SS_Log_Test.cpp) that is included in the sources. There are extensive comments, and it might take less time to pick up the jist of things there. That project will not show everything available to you, but should get you started. As some point you should read the article if you want to learn the full functionality from SS_Log.
The Global Log
The global log is a single instance of the SS_Log class that is available to all files that include SS_Log.h. You can begin using the global log immediately just by including that file, using the following macros:
1. INT Log(TCHAR* pMsg, ...);
2. INT Log(DWORD dwFilter, TCHAR* pMsg, ...);
3. INT LogID(UINT nResourceID, ...);
4. INT LogID(DWORD dwFilter, UINT nResourceID, ...);
The simplest form (the first macro above) takes an sprintf-style format string and a variable number of parameters that will be formatted into the final message.
The second macro allows you to include message flags that override the default flags (more on flags later). The third and fourth macros are duplicated of the first two, except that they take a resource ID as the format string.
You can access configuration options for the global log with the following macros (we will discuss each in turn):
5. DWORD LogSetFlags(DWORD dwFlags);
6. DWORD LogGetFlags();
7. DWORD LogRemoveFlags(DWORD dwFlags);
8. DWORD LogAddFlags(DWORD dwFlags);
9. INT LogSetDestinationName(LPCTSTR szName);
10. INT LogEraseLog();
11. INT LogLimitOutputSize(DWORD dwSizeLimit);
12. INT LogGetLastError();
13. INT LogSetRegistryKey(LPCTSTR szRegKey);
14. VOID LogUseServer(BOOL bUseServer);
15. BOOL LogSucceeded();
16. VOID LogInstanceHandle(HANDLE hInstance);
17. VOID LogEnterFunction(LPCTSTR szFunctionName);
The Server
The first configuration function we need to talk about is the LogUseServer() function. By default, the SS_Log class will launch a separate process, the SS_Log_Server application (which must be in the %SYSTEMROOT% directory), to capture all messages. There is one main reason for using a separate process: Speed. If we logged everything straight to a file (as the first version of SS_Log did), we would need to flush each and every message to disk immediately after it was logged to ensure that, in the event of a program crash, we didn't drop any messages. Flushing every message is VERY inefficient though, and can easily cause performance problems.
The SS_Log_Server class will be launched on demand and will prepare a named pipe to receive all messages. Then it will flush these messages out when it gets a chance, never hindering your application, which has long since moved on to other things. During testing, I logged over 100,000 messages in under 10 seconds (AMD 1700+) using the server, and only 1,000 in more than 10 seconds without the server. The server will even terminate itself when the instance of the SS_Log class that started it is destructed.
If for some reason you still don't want to use the server, the SS_Log class still supports flushing every message straight out to a file. Call the LogUseServer(FALSE) to use this behavior.
Flags
Macros 5-8 above allow the user to specify the default flags that will be sent with every message (unless overridden in the message). All flags are grouped into 3 categories:
- Level and User Flags
LOGTYPE_CRITICAL
LOGTYPE_WARNING
LOGTYPE_NORMAL
LOGTYPE_TRACE (default)
LOGTYPE_TRACE_FAIL
LOGTYPE_INOUT
- and any user defined types
- Build Type Flags
LOGTYPE_DEBUG (default in debug builds)
LOGTYPE_RELEASE (default in release builds)
- Destination Flags
LOGTYPE_LOGTOWINDOW (default)
LOGTYPE_LOGTOFILE (default)
LOGTYPE_LOGTOEVENTLOG
- and any user defined destinations
Call the LogAddFlags(...) and LogRemoveFlags(...) functions to add or remove any combination of flags using the bitwise OR operator ("|"). These two functions work just as expected in that the flags you pass in will be added or removed from the default list.
Use the LogSetFlags(...) to overwrite flags in the same group as those flags that you are passing in. This functionality may be a little different than expected. For example, if you were to call LogSetFlags(LOGTYPE_CRITICAL | LOGTYPE_LOGTOEVENTLOG), any currently set flags in the Level/User group will be overwritten by the LOGTYPE_CRITICAL flag, and any current ones in the destinations groups will be replaced with the LOGTYPE_LOGTOEVENTLOG. You can also ask for which flags are currently set as the defaults by calling LogGetFlags(...).
There are no restrictions on the combination of flags that can be set. Any number of flags from any group can be set at any time (ex. while it might not make much sense to set critical and warning flags, both can be set at the same time. On the other hand, it may well make sense to set multiple destinations, such as to file and to window).
All messages will be sent with the flags that are currently set, but you can override the current flags on a per-message-basis with macros #2 and #4 described above. When overriding the current flags, only those in the group passed in will be overridden (just as when calling the LogSetFlags(...) function).
Destinations and Destination Name
Currently there are three destinations available, though you can make your own (derive a class from the SSLogDestination class). Messages are "dispatched" to each destination for which one of the destination flags is set (see the destination flags listed above).
The With the LOGTYPE_LOGTOFILE flag set, all messages will be sent to the filename specified in the LogSetDestinationName(...) function. The file will be placed in the local directory of the calling application unless you specify otherwise in the destination name.
The LOGTYPE_LOGTOEVENTLOG flag will send all messages to the NT event log. Note that Win9x can be configured to send these messages to a file (see the MSDN ReportEvent() and RegisterEventSource() functions for details).
The LOGTYPE_LOGTOWINDOW flag is more unique. The "window" (which we will call the "viewer") is actually an MFC single document application that is part of the SS_Log_Server.exe. All messages will be sent to the server, and the server will display this single document window, placing the messages in a list view. More details on the viewer below.
Error Handling
Call LogGetLastError() to get one of the SS_Log defined errors, found here. Use LogSucceeded() to get a BOOL value stating whether or not the last call was a success.
Other Commands
The LogEraseLog() macro will cause the viewer and file destinations to erase their logs. The NT event log is unaffected by this call.
The LogLimitOutputSize() macro currently only affects the file destination. Pass in the number of kilobytes that you do not want your log file to exceed. The file destination will monitor the file size, and when a message will cause it to exceed this size, the file will be trimmed in half, throwing away the oldest 50% of the messages and making room for new ones.
The LogSetRegistryKey() macro controls where in the registry SS_Log will keep its settings. This allows you to use the SS_Log in multiple projects and not have them bump heads. Note that currently you only get to specify a portion of the key. If you pass in "MyCompany\MyApp" as your registry key, the SS_Log will store its settings in HKEY_LOCAL_MACHINE\Software\MyCompany\MyApp\SS_Log.
The LogInstanceHandle() macro will give the SS_Log class your application's instance handle, which is necessary when using the LogID(...) macros. If you don't set the instance handle first, calls to LogID(...) will fail.
The LogEnterFunction() macro actually logs two messages. Call this function when entering a function and pass in the function's name. An "Entering MyFunction" message will be created when this line of code is run AND an "Exiting MyFunction" message will be sent when the function exits.
Disabling Logging
You can compile out all logging to the global log by simply not #defining _SS_LOG_ACTIVE. This will also compile out all logging for local logs ONLY IF you compile the SS_Log.cpp and SS_Log_Defines.cpp files with your project rather than linking to the SS_Log.lib and SS_LogD.lib files.
Regardless of whether or not you #define _SS_LOG_ACTIVE, you can still eliminate ALL logging by setting the "LoggingDisabled" value in the registry to 1 (or anything other than 0). Each instance of the SS_Log will read this value in during construction and obey it's value. The registry will be re-read when the user specify's a different registry key in a call to the SetRegistryKey function described above. Currently I have not provided a way to programmatically set this value. You must set this value in the registry manually (i.e. open regedit).
The Complete class documentation can be found at http://sslog.webhop.net.
Creating Multiple Local Logs
Up to now, everything you've learned has been centered around the Global Log. This log is simple a globally available instance of the SS_Log class that was created for you when your application fired up. You are not limited to using this log, however. You can create as many "local logs" as you need. This will help you to keep different information separate (such as logging to separate logs per thread, per module, or however you'd like to organize it).
To create your own instance of the SS_Log class and log two messages to it, use the following code:
SS_Log myLog("MyServerName");
Log(&myLog, "This is my value: %d.", nMyValue);
LogID(&myLog, nResourceID);
The first time you log a message, your instance will launch a new server (even if one has already been launched from the global log). All messages from this instance will be sent to that server. The server will close itself once this instance of the SS_Log is destructed.
You can access all the configuration functions just like in the global log, except that you don't use the macros:
18. DWORD myLog.SetFlags(DWORD dwFlags);
19. DWORD myLog.GetFlags();
20. DWORD myLog.RemoveFlags(DWORD dwFlags);
21. DWORD myLog.AddFlags(DWORD dwFlags);
22. INT myLog.SetDestinationName(LPCTSTR szName);
23. INT myLog.ErasemyLog.();
24. INT myLog.LimitOutputSize(DWORD dwSizeLimit);
25. INT myLog.GetLastError();
26. INT myLog.SetRegistryKey(LPCTSTR szRegKey);
27. VOID myLog.UseServer(BOOL bUseServer);
28. BOOL myLog.Succeeded();
29. VOID myLog.InstanceHandle(HANDLE hInstance);
30. VOID LocalLogEnterFunction(SS_Log* pLog, LPCTSTR szFunctionName);
A couple things to note:
- You can pass SS_Log pointers between threads and log from them simultaneously. The SS_Log class is thread safe on a per instance basis (but not across instances, see note #2).
- You CAN bind two (or more) SS_Log instances to the same server by passing in the same name in the constructor. The first instance that logs a message will spawn the server, and all instances after that will bind to that same server rather than spawning a new one of their own. BUT THIS IS NOT RECOMMENDED in multi-threaded apps, because if two separate instances of the SS_Log class both try to write to the server at the same time (from separate threads), one of the two messages will get dropped.
- You can even bind SS_Log's in different processes to the same server, but the same problem mentioned in note #2 applies.
Using the Viewer
The viewer (or "window") and the server are both one app (SS_Log_Server.exe). As described earlier, the SS_Log class will start an instance of the server when needed, and terminate that server when it is done. What wasn't mentioned is that if you had the LOGTYPE_LOGTOWINDOW flag set on any of the messages that were sent to the server and if the filter in the registry is allowing LOGTYPE_LOGTOWINDOW messages to be processed, that instance of the SS_Log_Server will remain open and display its window even after the SS_Log that started it is destructed. This is so you can view the messages that were logged to the window.
You can also start the SS_Log_Server.exe yourself and open logs saved for sorting/filtering/printing/jumping to code (the print output is weak at best... if anyone wants to have a go at improving it, I'll integrate your code ;-). Files that have been written out with the file destination (the LOGTYPE_LOGTOFILE flag) and files that were saved by the viewer itself can both be opened.
Filter Incoming Server Messages (destructive)
You can filter messages in two ways. The first is by filtering out messages as they come into the server. When using this method of filtering, the messages are simply thrown away, leave no way to retrieve them in the future (hence the "destructive" term).
You can turn these filters on and off by clicking on "Edit->Filter Incoming Server Messages (destructive)" in the server window (options that are grayed out are not supported in this filter mode). A dialog will pop up will checkboxes for each flag type (including user defined flag types, discussed in the Create You Own Filters section). For a message to arrive at its destination(s), at least 1 flag IN EACH GROUP must be set and the corresponding filter must be turned on.
You can also turn the filters on and off directly in the registry. They will be located where you specified with a call to the SetRegistryKey(...) function. If you never call that function, the SS_Log class defaults to behaving as if you had called it and passed in "SS_Log" (see "#SetRegistryKey">SetRegistryKey(...)).
Note that because these filters are maintained in the registry, they will remain active across separate "runs" of your program.
Filter Listview (non-destructive)
Rather than doing destructive filtering, you can leave all the Incoming Server Messages filters on and then do dynamic filtering in the viewer after your app has terminated. Click on "Edit->Filter Listview (non-destructive)" to see your options. In addition to turning on and off the flag type filters, you can filter by message text, filename, and message ID. You can also specify if all flags or only 1 flag must be set for the message to appear in the view.
Note that because these filters are maintained in the registry, they will remain active across separate "runs" of your program. This can be confusing if, for example, you forget that you left a message text filter on and none of your new messages seem to be showing up. Just turn off the filter and they will re-appear. Also note that when saving, ALL messages in the server will be saved to file, even if they are filtered out of the view by the view filters. Printing, however, prints only what is currently in the view, properly obeying the view filters.
Jump To Code in Visual Studio
Probably the neatest feature about the viewer is it's ability make Visual Studio jump to a file and line number. Just double-click on a logged message and Visual Studio will open that file and move to the line that produced the log (if there is not an instance of Visual Studio running, one will be launched). Note that the first time you do that, the viewer will need to install the SS_Log_AddIn.dll as a plug-in to VC++. Make sure you have that file in your %SYSTEMROOT% folder, and that there are no instances of VC++ running during the install.
Creating Your Own Filters
It is very easy to expand the flags with the SS_Log class. The steps to do so are as follows:
- Look in the SS_Log_Defines.h file for the definition of
SS_LogFilterType, defined as typedef enum SS_LogFilterType{...}. Add a LOGTYPE_* entry to that enum list (i.e. LOGTYPE_XYZ) and just assign it the next bit available in line (ex. LOGTYPE_XYZ = (1<<9)).
- Add your new filter type to the
LOGTYPE_USERS #define just below the SS_LogFilterType enum. Use the bitwise OR ("|") operator (ex. #define LOGTYPEGROUP_USERS ( LOGTYPE_ADD_YOUR_TYPE_HERE | LOGTYPE_XYZ )).
- In the SS_Log_Defines.cpp file, find the
SSLogFilter g_Filters[] object and add an entry to that array. The entry should include 3 items:
- the
LOGTYPE_XYZ enum value you just added to the SS_LogFilterType enum.
- a string that will be shown in the Filter column of the log window.
- a string that will be written into the registry... the registry entry can be used to turn that filter on and off (with a 1 or 0 value).
That's all! One you run your app for the first time (so the new registry entry can be written to the registry), the new filter will appear in the viewer's filter menus, and everything should work as expected. Note that all user flags are part of the levels/user group of flags (creating a destination flag is an exception, but requires much more effort).
Creating Your Own Destinations
You can create your own log destination by deriving a class from the SSLogDestination class. There are several overrides that you can implement to receive notification of messages and configuration options sent from an SS_Log instance. These overrides include:
virtual BOOL OnWriteMessage (LOGMESSAGE* pMsg) = 0;
virtual BOOL OnSetDestinationName (LOGMESSAGE* pMsg);
virtual BOOL OnEraseLog (LOGMESSAGE* pMsg);
virtual BOOL OnLimitOutputSize (LOGMESSAGE* pMsg);
virtual BOOL OnSetRegistryKey (LOGMESSAGE* pMsg);
virtual BOOL OnShutDownServer ();
virtual BOOL OnBeginUpdate ();
virtual BOOL OnFinishUpdate ();
virtual BOOL WillProcessMessage (LOGMESSAGE* pMsg);
The LOGMESSAGE class contains all the information sent with the message from the SS_Log class. It can be found in the stdafx.h file in the SS_Log_Server project, and has the following accessor methods:
INT MessageID ();
INT ProcessingID ();
DWORD Flags ();
LPSTR Message ();
LPSTR DateTime ();
LPSTR Filename ();
INT LineNumber ();
MSGTYPE MessageType ();
VOID MessageID (INT nID);
VOID ProcessingID (INT nID);
VOID Flags (DWORD nFlags);
VOID Message (LPSTR szMsg);
VOID DateTime (LPSTR szDT);
VOID Filename (LPSTR szFile);
VOID LineNumber (INT nLine);
VOID MessageType (MSGTYPE nType);
The message dispatching routine in the server (see the SSLogOutput.cpp file) will check every 5 seconds to see whether or not the server has received new messages for dispatch. If there are new messages, each destination will get an OnBeginUpdate notification. Then, for each new message, the server will call each destination's WillProcessMessage function to determine whether or not we will be logging the message. This function should return TRUE or FALSE after checking the flags for the message passed in and comparing them against the currently set filters. Note that the default implementation of WillProcessMessage will handle most destinations' needs.
If the WillProcessMessage returns TRUE, the OnWriteMessage function will be called for that message. Your class MUST override this function and do with the message as you will at that point.
Once all new messages have been dispatched, the OnFinishUpdate function will be called as a notification that all messages are processed. If the server has received a shutdown request from the SS_Log class, and if no other instances of the SS_Log class are still bound to the server, then your derived class will then receive the OnShutDownServer message in case you need to do some cleanup.
All other override functions contain configuration data. You can retrieve the configuration data from the LOGMESSAGE's Message() function (passed into the function as the only parameter). The info will be returned in ANSI text format. Note that even though the OnEraseLog function has a LOGMESSAGE parameter, no information is currently stored in it.
Of course, you will need to add a flag to the SS_Log_Defines.h file as described in the Creating Your Own Filters section. Note however, that you should associate the flag with the Destinations group rather than with the Users group. You will also need to create a new instance of your destination type during start up of the server. This can be done in the SSLogOutput::CreateDestination function in the SSLogOutput.cpp file.
History
Version 3.01
- Fixed the "flash" made by the server's window during startup. We no longer see this window for a split second during startup.
- Fixed a potential (though unlikely) crash in the server's message dispatch thread where outputting messages while simultaneously receiving new messages (the dirty flag).
- Added the ability to jump to code for "exiting function" messages. Also added an "ID" to these messages, which will be used to match multiple entering and exiting calls of the same function.
- Added the "+++++" and "-----" to the exiting and entering function messages for easier viewing. (suggestion by Forogar)
- Added viewer feature that, when the user selects an exiting or entering function message, the viewer also selects the corresponding message. (request by Forogar)
- Added "DisableLogging" registy entry, so that now the user can disable the logging altogether by setting this registy entry to false (0).
- Unicode enabled (29 Mar 03)
Version 3
This is the first version to use the SS_Log_Server and the new architecture. Previous versions were not documented.
Comments
Please feel free to ask questions, offer comments/suggestions, etc. I'm glad to listen and help.
