Each self-respecting programmer and software team uses logging features.

In my current job on ASP.NET, each click, every navigation and message is logged. Very handy indeed because you would like to support your customers.

 For a classic C++ project this is not so easy to do. You can use ATLTRACE2 or AtlTrace and these macro's have the advantage that at release time, they won't stuff your code with unnecessary statements.

However, in case you have a support incident on your code that runs with a client, you'll have to add tools or to deliver windbg.exe to read those statements and to hand over a debug dll or exe. And you have to instruct your customers to save the log to a file. I'm not happy at this of course, I might be mistaken and some C++ expert tells me how easy this could be done in fact. ;).

So I wrote such a class. It is tested on several processes (as asp can do, several w3wp.exe processes can load your COM dll) that write to a single log file.

So what do we need to care for?

  1. Log to a single file from one or more processes that load my specific COM dll
  2. Log to 1) Debug Output 2) a file 3) both, 4) none
  3. If logging is switched off, it must not cause performance degration.
  4. If we write to the file, we must synchronize, we use a Mutex.
  5. Our code that utilizes this class, must (preferable) access a singleton instance of our class per DLL

Here comes the source...

class LoggingModule

{

public:

      LoggingModule() ;

      ~LoggingModule();

      //releases resources

      void Close(bool deleteLogFile = false);

      void Write(PCWSTR pszFormat, ...);

      void set_Logging(int enable);

      // 0 = %windir%\Temp, 1=%userprofile%\Local Settings\Temp

      void set_TempLocation(int location);

      int get_Logging();

private:

      CAtlFile m_file;

      //0 disabled 1 = to file, 2 = to Debug 3 = both

      int m_LoggingEnabled;

      int m_tempLocation;

      HANDLE m_hMutex; 

      CComBSTR m_MutexName ;

      //member variable, so we enable BSTR caching. A lot more efficient

      CComBSTR m_bstrTrace, m_logFileName, m_fmt;

};
extern LoggingModule logModule;

// implementation of LoggingModule

LoggingModule::LoggingModule(void) throw() :

      m_LoggingEnabled(0),

      m_hMutex(NULL)

{

}

void LoggingModule::set_TempLocation(int location) throw()

{

      m_tempLocation = location;

}

void LoggingModule::set_Logging(int enable) throw()

{

      m_LoggingEnabled = enable;

      if ((m_LoggingEnabled & 1) == 1)

      {    

            m_logFileName.SetLength(MAX_PATH);

     

            DWORD bufLen = GetModuleFileNameW(_AtlBaseModule.GetModuleInstance(), m_logFileName, MAX_PATH);

            PathStripPathW(m_logFileName);

            PathRenameExtensionW(m_logFileName, L".LOG");

            //strip right length

            m_logFileName.SetLength((unsigned int)wcslen(m_logFileName));

            m_MutexName = L"Global\\";

            m_MutexName += m_logFileName;

            CComBSTR buf(MAX_PATH);

            if (m_tempLocation == 0)

                  bufLen = GetSystemWindowsDirectoryW(buf, MAX_PATH);

            else

                  bufLen = GetTempPathW(MAX_PATH, buf);

            if (bufLen == 0)

            {

                  buf.Format(L"error %d\n", GetLastError());

                  OutputDebugStringW(buf);

                  m_logFileName.Empty();

                  m_LoggingEnabled ^= 1; //disable file logging

                  return;

            }

            else

            {

                  //strip right length again

                  buf.SetLength(bufLen);

                  buf += L"\\TEMP\\";

                  buf += m_logFileName;

                  // now m_LogFileName looks like C:\Windows\Temp\myDll.Log

                  m_logFileName.Attach(buf.Detach());

            }

            //Create EveryOne in a language independend way

            SID_IDENTIFIER_AUTHORITY sia = {SECURITY_WORLD_SID_AUTHORITY};

            CSid everyone(sia, 1, SECURITY_WORLD_RID);

            // we must use a Security Descriptor, otherwise other w3wp.exe processes cannot

            // inherit the mutex!

            CSecurityDescriptor secDescr;

            // ATL does not initialize this object at construction??

            HRESULT hr = secDescr.Initialize();      

            if (hr == S_OK) hr = secDescr.Allow((PSID)everyone.GetPSID(), MUTANT_ALL_ACCESS);     

            if (FAILED(hr))

            {

                  buf.Format(L"secDescr.Allow failed with %x\n",hr);

                  OutputDebugStringW(buf);

                  m_LoggingEnabled ^= 1;

                  return;

            }

            SECURITY_ATTRIBUTES SecAttrs = {sizeof(SecAttrs), secDescr, TRUE};

            // create the mutex without owning it.

            // if another process (w3wp) already did the creation

            // we just ignore the error and m_hMutex stays nill

            m_hMutex = CreateMutexW(&SecAttrs, FALSE, m_MutexName);

            if (m_file == NULL  || m_logFileName.IsEmpty())

            {

                  hr = m_file.Create(m_logFileName,

                        FILE_GENERIC_WRITE,

                        FILE_SHARE_READ | FILE_SHARE_WRITE,

                        OPEN_ALWAYS);

                 

                  if (SUCCEEDED(hr))

                  {

                        ULONGLONG sz;

                        if (SUCCEEDED(m_file.GetSize(sz)))

                        {

                              //it's a unicode-8 logfile

                              if (sz == 0)

                              {

                                    BYTE PreAmble[] = {0xEF, 0xBB, 0xBF};

                                    m_file.Write(PreAmble, sizeof(PreAmble));                  

                              }

                              //TODO: finish

                              else if (sz > 10000)

                              {

                                    //truncate first 5000 lines and restart

                              }

                              m_file.Seek(sz);

                        }

                  }

                  else

                  {

                        buf.Format(L"Could not create %s, error %x\n", m_logFileName, hr);

                        OutputDebugStringW(buf);

                        // do not bother to write to the logfile

                        m_LoggingEnabled ^= 1;

                  }

            }          

      }

      else

            Close();

     

}

int LoggingModule::get_Logging() throw()

{

      return m_LoggingEnabled;

}

LoggingModule::~LoggingModule(void) throw()

{

      this->Close();

}

///<sumarray> releases resources</summary>

void LoggingModule::Close(bool deleteLogFile) throw()

{

      m_file.Close();

      m_bstrTrace.Empty();

      if (m_hMutex  != NULL)

      {

            CloseHandle(m_hMutex);

            m_hMutex = NULL;

      }

      if (deleteLogFile && !m_logFileName.IsEmpty())

            DeleteFileW(m_logFileName);

      m_logFileName.Empty();

      m_fmt.Empty();

}

// this function writes the debugging information to the logfile

// it synchronizes on a mutex so all processes go through this bottleneck

// and will 'fight' for file access

// be sure not to enable such a thing in production

void LoggingModule::Write(PCWSTR pszFormat, ...) throw()

{

      bool noFileAccess = false;

      HANDLE mutResult = NULL;

      if (m_LoggingEnabled == 0)

            return;

      else if ((m_LoggingEnabled & 1) == 1)

      {

            mutResult = OpenMutexW(MUTANT_ALL_ACCESS, FALSE, MUTEXNAME);

            if (mutResult != NULL)

            {

                  DWORD dwWaitResult = WaitForSingleObject(

                              mutResult,   // handle to mutex

                              5000L);   // five-second time-out interval

       

                  switch (dwWaitResult)

                  {

                        // The thread got mutex ownership.

                  case WAIT_OBJECT_0: break; //ok

                  // Cannot get mutex ownership due to time-out.

                  case WAIT_TIMEOUT:

                  // Got ownership of the abandoned mutex object.

                  case WAIT_ABANDONED:

                        OutputDebugStringW(L"error on LoggingModule::Write OpenMutex\n");

                        noFileAccess = true;

                        break;

                  }

            }

            else

            {

                  m_fmt.Format(L"coult not create mutex to %s err(%d)\n", m_logFileName, GetLastError());

                  OutputDebugStringW(m_fmt);

                  noFileAccess = true;

            }

      }

      va_list ptr;

      va_start(ptr, pszFormat);    

      m_bstrTrace.Format(pszFormat, ptr);

      va_end(ptr);

      SYSTEMTIME st ;

      GetLocalTime(&st);

      //prepend debugstring with thread and time.

      // eg 1040{tab}10:40:50:0599{tab}msg

      m_fmt.Format(L"%d\t%02d:%02d:%02d:%04d\t", GetCurrentThreadId(),

                  st.wHour, st.wMinute, st.wSecond, st.wMilliseconds);       

     

      bool appendCrLf = !m_bstrTrace.EndsWith(L"\n");

      m_bstrTrace.Insert(0, m_fmt);

      if ((m_LoggingEnabled & 2) == 2)

      {

            OutputDebugStringW(m_bstrTrace);

            if (appendCrLf)

                  OutputDebugStringW(L"\n");

      }

      // write only to the file if we have access

      if (m_file != NULL && !noFileAccess && (m_LoggingEnabled & 1) == 1)

      {

            ULONGLONG nCurLen;

            m_file.GetSize(nCurLen);

            m_file.Seek(nCurLen, FILE_BEGIN);

            if (appendCrLf)              

                  m_bstrTrace.Append(L"\r\n", 2);                      

           

            m_fmt.Attach(m_bstrTrace.ToByteString());

            m_file.Write(m_fmt, m_fmt.ByteLength());                 

            //clear buffer so we can be sure the buffer advances

            m_file.Flush();

            if (mutResult != NULL)

            {

                  //release ownership

                  ReleaseMutex(mutResult);

                  //close handle (because it is a duplicate!)

                  CloseHandle(mutResult);

            }

      }

}

// in your main CPP file you create -one instance- of this class.

LoggingModule logModule;

Remarks about the code.

  1. the CComBSTR code uses method that are not available by default. To use the super-power-CComBSTR replacement, see my other Blog posting about this class (expect over 3000% bstr performance improvements)
  2. This class minimizes file access by prebuffering the debug string.
  3. It will log to \%windir%\temp\nameofyourdll.log
  4. It writes the log as in utf-8 format.
  5. Fans of my code Smile already know that I have abandoned win9x compatibility. This code runs only WinNT and higher.
  6. It uses ATL. So if you use MFC for instance, you'll have to replace the CSecurityDescriptor class with an alternative or direct Win API equivalents (which I dislike for being so complex).
  7. dependencies: <atlfile.h>, CComBStr2.h, <atlsecurity.h>, <security.h>