[Okta Webinar] Learn how to a build a cloud-first strategyRegister Now

x
?
Solved

TRACE hangs on multithread application

Posted on 2004-10-27
20
Medium Priority
?
754 Views
Last Modified: 2013-11-20
I have a multithread application that hangs on the TRACE command.
I've tried using CMutex and CCriticalSection objects to make sure more then one thread is not calling it at the same time, but it still hangs.

Here's the code:
void Log::LogData(CString Data, LogLevel Level)
{
      CMutex blockingObj;
      CSingleLock singlelock(&blockingObj, TRUE);
      static CStdioFile &file = InitializeLoggging();
      static LogLevel MaxLogLevel = GetLevelOption();
      static int QtyLogs = 0;
      const int MaxQtyBeforeFlushing = 10;
      if (Level > MaxLogLevel) return;
      CTime currentTime(CTime::GetCurrentTime());
      Data.Format(Data, currentTime.Format("%d-%m-%y:%H:%M:%S"));
      file.WriteString(Data);
      ++QtyLogs;
      if (Level == LOG_ALWAYS || QtyLogs > MaxLogLevel)
      {
            QtyLogs = 0;
            file.Flush();
      }
      TRACE(Data);  //********HANGS here
}

It doesn't hang right away.  It usually hangs after it's called over 300 times.

If I comment out TRACE, then the program works just fine.

Anyone know how I can fix this?
0
Comment
Question by:Axter
  • 9
  • 5
  • 4
  • +1
20 Comments
 
LVL 86

Expert Comment

by:jkr
ID: 12425096
Have you tried using 'OutputDebugString()' directly instead of 'TRACE()'?
0
 
LVL 30

Author Comment

by:Axter
ID: 12425118
>>Have you tried using 'OutputDebugString()' directly instead of 'TRACE()'?

That's the first thing I tried.

When that failed, I then started using TRACE.

They both fail the same.
0
 
LVL 86

Assisted Solution

by:jkr
jkr earned 400 total points
ID: 12425214
How big can 'Data' be (in terms of length)?
0
Technology Partners: We Want Your Opinion!

We value your feedback.

Take our survey and automatically be enter to win anyone of the following:
Yeti Cooler, Amazon eGift Card, and Movie eGift Card!

 
LVL 30

Author Comment

by:Axter
ID: 12426449
No more then 200 characters per line.
0
 
LVL 86

Expert Comment

by:jkr
ID: 12426889
Hm, I was hoping it would be a lot more. Actually, I have an app that creates >30MB traces (in smaller chunks, of course) from several threads and never had that problem... I should mention though that the logging feature is syc'ed by a singleton lock.
0
 
LVL 30

Author Comment

by:Axter
ID: 12429461
>>I should mention though that the logging feature is syc'ed by a singleton lock.

How would that differ from a CMutex?
0
 
LVL 86

Expert Comment

by:jkr
ID: 12429603
Not at all. But, it's a process global lock for that subsystem, IOW: Every log message from that DLL is sync'ed with a critical section that serves only that purpose, e.g.

void Log::LogData(CString Data, LogLevel Level)
{

    g_csLogData.Lock();

    // ....

    g_csLogData.Unlock();

}

0
 
LVL 86

Expert Comment

by:jkr
ID: 12429624
>>singleton lock

That was probably a poor description, it is just a lock object realized as a singleton...
0
 
LVL 9

Expert Comment

by:Priyesh
ID: 12430389
Have you tried making the CMutex blockingObj; as a member of the Log class?
0
 
LVL 30

Author Comment

by:Axter
ID: 12433371
>>Have you tried making the CMutex blockingObj; as a member of the Log class?
I wouldn't be able to that, since Log::LogData is a static member function.
0
 
LVL 30

Author Comment

by:Axter
ID: 12433380
Actually, I could make it a static member variable, but I don't see how this would make much of a difference.

I'll try it any way.
0
 
LVL 9

Expert Comment

by:Priyesh
ID: 12441318
>>but I don't see how this would make much of a difference.

If you are constructing an unnamed mutex locally, each time the CMutex constructor will execute a ::CreateMutex call and return a new handle. This means your CSingleLock is operating on a brand new sync object each time. So in effect, there is no synchronization. To achieve proper synchronization, you need to make sure there is only one mutex handle and one way would be to make it static as you stated above.

so the key is to have your syncobject constructed once and kept throughout the time you need synchronization.

0
 
LVL 30

Author Comment

by:Axter
ID: 12442971
>>To achieve proper synchronization, you need to make sure there is only one mutex handle and one way would be to make it static as you stated above.

I tried it as a member variable, and it still fails.
0
 
LVL 39

Expert Comment

by:itsmeandnobodyelse
ID: 12724666
>> I tried it as a member variable, and it still fails

It has to be a static class member or it would work only with the current Log instance. You also could use a global mutex instance or both as the following sample of (one of) my string class(es) shows:

static CriticalSection g_cs;

// Mutex used when changing m_nRefCount
CriticalSection* StringBuf::m_pCs      = &g_cs; // m_pcs is a static member

Regards, Alex


0
 
LVL 39

Expert Comment

by:itsmeandnobodyelse
ID: 12724706
Here is a sample of an older Trace class (not based on C++ standard but used on UNIX, WIN and OS/2 platforms) that works in a multi-threaded environment (up to 100 threads managed by a dynamic thread-pool)

Regards, Alex


// trace.hpp

#ifndef TRACE_HPP
#define TRACE_HPP

#ifndef BASTYPES_HPP
   #include <bastypes.hpp>
#endif

#ifndef BASEXCPT_HPP
    #include <basexcpt.hpp>
#endif

#ifndef STRING_HPP
   #include <string.hpp>
#endif

#ifndef MUTEX_HPP
   #include <mutex.hpp>
#endif

#ifndef REFCOUNT_HPP
   #include <refcount.hpp>
#endif

#include <sys/types.h>
#include <sys/stat.h>
#include <time.h>

#ifdef close
   #undef close
#endif

#include <fstream>

#if defined (NT) || defined (OS2)
   #include <sstream>
#else
   #include <strstream.h>
#endif

using namespace std;

/////////////////////////////////////////////////////////////////////////////
// @doc
//
// @module  trace.hpp - Header for Tracing |
//          defines a trace class and some useful macros
//          for debug, error and info output on file
//
/////////////////////////////////////////////////////////////////////////////

// @enum Severity codes to control tracing
enum SeverityCode
{
   SEV_NONE  = -1,      // @emem output to trace file, no trace info required
   SEV_SYSINFO,         // @emem internal messages
   SEV_DEBUG,           // @emem only for debugging purposes
   SEV_INFO,            // @emem info messages; no action required
   SEV_HINT,            // @emem info messages with recommended action required
   SEV_WARNING,         // @emem warnings or no severe errors
   SEV_ERROR,           // @emem severe errors or mal functions
   SEV_FATAL            // @emem fatal errors where an immediate action is required
   
};

class TraceFile;

// @globalv max number of saved versions of the same trace file
extern Long            g_numTraceFileCopies;
// @globalv max size of a trace file before a new version is opened
extern Long            g_maxTraceFileSize;
// @globalv max size of output before the file is reopened
extern Long            g_maxOutputBeforeClose;
// @globalv number of secs for same message to trace
extern Long            g_delaySameMessage;
// @globalv severity level for private traces; all lower severities will be suppressed
extern Int             g_privTraceLevel;
// @globalv severity level for system traces; all lower severities will be suppressed
extern Int             g_sysTraceLevel;
// @globalv severity level for operator mails
extern Int             g_mailLevel;
// @globalv name of system trace file
extern CharPtr         g_pszTraceFile;

extern RefCounter*                  g_pFileCount;        // @cmember number of trace files registered
extern TraceFile**                  g_fileArr;           // @cmember dictionary of all trace files
extern Int                          g_lastSame;          // @cmember number of repititions of same message
extern CharPtr                      g_pszLastMessage;    // @cmember last message
extern Int                          g_lastFileId;        // @cmember last file
extern SeverityCode                 g_lastSevCode;       // @cmember last severity code
extern CharPtr                      g_pszLastSourceFile; // @cmember last source file
extern Int                          g_lastLineNo;        // @cmember last source code line number
extern Int                          g_fileArrAlloc;      // @cmember no of allocated file names
extern Int                          g_fileArrFilled;     // @cmember no of used file names
extern time_t                       g_lastTime;          // @cmember last time stored
extern CriticalSection*             g_pcs;               // @cmember to make tracing thread-safe
extern ULong*                       g_threadArr;         // @cmember array to hold the thread id of all calling threads
extern Int                          g_threadArrAlloc;    // @cmember no of allocated thread ids
extern Int                          g_threadArrFilled;   // @cmember no of used thread ids
extern ULong                        g_threadId;          // @cmember last thread id
extern Char                         g_szThreadIdChars[]; // @cmember letters to identify threads    


// @func Macro | BAS_TRACE | trace output on file tracking source file and line number
// @parm ConstCharPtr | text     | trace text
// @parm SeverityCode | severity | One of SEV_DEBUG/SEV_INFO/SEV_HINT/SEV_WARNING/SEV_ERROR/SEV_FATAL
// @parm ConstCharPtr | file     | (path to) trace file
#define BAS_TRACE(text, severity, file) \
{ostringstream os##__LINE__; TraceFile::trace(__FILE__, __LINE__, (ostringstream&)(os##__LINE__<<text), severity, file);}
// @func Macro | BAS_ERROR | error output on standard error trace file
// @parm ConstCharPtr | text     | trace text
#define BAS_ERROR(text) \
{ostringstream os##__LINE__; TraceFile::trace(__FILE__, __LINE__, (ostringstream&)(os##__LINE__<<text), SEV_ERROR);}
// @func Macro | BAS_DEBUG | debug output on private trace file
// @parm ConstCharPtr | text     | trace text
// @parm ConstCharPtr | file     | (path to) trace file
#define BAS_DEBUG_FILE(text, file) \
{ostringstream os##__LINE__; TraceFile::trace(__FILE__, __LINE__, (ostringstream&)(os##__LINE__<<text), SEV_DEBUG, file);}
// @func Macro | BAS_TRACE_SYSTEM | trace output with severity on standard error trace file
// @parm ConstCharPtr | text     | trace text
// @parm SeverityCode | severity | One of SEV_DEBUG/SEV_INFO/SEV_HINT/SEV_WARNING/SEV_ERROR/SEV_FATAL
#define BAS_TRACE_SYSTEM(text, severity) \
{ostringstream os##__LINE__; TraceFile::trace(__FILE__, __LINE__, (ostringstream&)(os##__LINE__<<text), severity);}
// @func Macro | BAS_DEBUG | debug output on standard error trace file
// @parm ConstCharPtr | text     | trace text
#define BAS_DEBUG(text) \
{ostringstream os##__LINE__; TraceFile::trace(__FILE__, __LINE__, (ostringstream&)(os##__LINE__<<text), SEV_DEBUG);}
// @func Macro | BAS_INFO | info output on standard error trace file
// @parm ConstCharPtr | text     | trace text
#define BAS_INFO(text) \
{ostringstream os##__LINE__; TraceFile::trace(__FILE__, __LINE__, (ostringstream&)(os##__LINE__<<text), SEV_INFO);}
// @func Macro | BAS_HINT | hint output on standard error trace file
// @parm ConstCharPtr | text     | trace text
#define BAS_HINT(text) \
{ostringstream os##__LINE__; TraceFile::trace(__FILE__, __LINE__, (ostringstream&)(os##__LINE__<<text), SEV_HINT);}
// @func Macro | BAS_WARNING | warning output on standard error trace file
// @parm ConstCharPtr | text     | trace text
#define BAS_WARNING(text) \
{ostringstream os##__LINE__; TraceFile::trace(__FILE__, __LINE__, (ostringstream&)(os##__LINE__<<text), SEV_WARNING);}
// @func Macro | BAS_FATAL | fatal error output on standard error trace file
// @parm ConstCharPtr | text     | trace text
#define BAS_FATAL(text) \
{ostringstream os##__LINE__; TraceFile::trace(__FILE__, __LINE__, (ostringstream&)(os##__LINE__<<text), SEV_FATAL);}

// @class Trace class for error logging, debugging and runtime info
//
class TraceFile
{
// @dataprivate
private:
   Int               m_fileId;               // @cmember (unique) index of file in file map
   CharPtr           m_pFileName;            // @cmember name of file (in small letters)
   ofstream          m_of;                   // @cmember file stream of trace file
   Long              m_filled;               // @cmember number of bytes filled
   Bool              m_bOpen;                // @cmember file is open
   Bool              m_bStdErr;              // @cmember no file but stderr

// @funcpublic
public:
   // @cmember default constructor
   TraceFile()
      : m_fileId(0), m_pFileName(NULL), m_filled(0), m_bOpen(False), m_bStdErr(False) {}
   // @cmember destructor; removes file from map
   ~TraceFile();

   // @cmember get file index
   Int               getFileId()
      { return m_fileId; }
   // @cmember get file name
   ConstCharPtr      getFileName()
   {
      return m_pFileName;
   }
   // @cmember check if file is open
   Bool              isOpen()
      { return m_bOpen; }
   // @cmember check if file is stderr
   Bool              isStdErr()
      { return m_bStdErr; }
   // @cmember open file for writing; add file to map
   Bool              open(ConstCharPtr fileName);
   // @cmember reopen file to free buffers
   Bool              reopen();

   // @cmember output stream operator for strings
   TraceFile&        operator << (ConstCharPtr str);
   // @cmember output stream operator for single characters
   TraceFile&        operator << (Char c);
   // @cmember output stream operator for ostream functions (such as endl)
   TraceFile&        operator <<(ostream& (* _f)(ostream&));

   // @cmember close file
   void              close();

   // @cmember rename old trace file and open a new one keeping a defined number of copies
   Bool              getNewTraceFileVersion();
   // @cmember write trace  to stream
   void              out(ostringstream& os, SeverityCode sevCode, ConstCharPtr sourceFile, Int lineNo, Char cThread = ' ');

   // @cmember find TraceFile object by filename
   static TraceFile* getTraceFile(ConstCharPtr pFileName);
   // @cmember get new (next) file index
   static Int        getNewId();
   // @cmember do the tracing
   static Bool       trace(ConstCharPtr sourceFile, Int lineNo, ostringstream& text,
                           SeverityCode sevCode = SEV_ERROR,  ConstCharPtr traceFile = "");
   // @cmember close all trace files and remove them from map
   static void       removeAll();
   // @cmember close a trace files and remove them from map
   static void       close(ConstCharPtr traceFile);

   static void traceConditionFailure(ConstCharPtr message, ConstCharPtr condition, Int bCond, ConstCharPtr file, Int line);
};


/*****************************************************************************/
/*               Module initialization               */
/*****************************************************************************/

// @func
// Initialize the trace module.
void initTrace (const char* traceFileName);

#endif


// trace.cpp

#include <string.h>
#include <stdlib.h>
#include <errno.h>
#include <config.hpp>
#include <trace.hpp>
#include <datetime.hpp>

#if defined (OS2) || defined (__WATCOMC__)
   #include <stddef.h>
   #define getThreadId() *(__threadid())
   #define PROT_SH_READ  S_IREAD
   #define PROT_SH_WRITE S_IWRITE
#else
   #define PROT_SH_READ  filebuf::sh_read
   #define PROT_SH_WRITE filebuf::sh_write
   #if defined (NT)
      #include <stddef.h>
      #define getThreadId() __threadid()
   #endif

   #if defined (AIX) || defined (LINUX)
      #include <pthread.h>
      #define getThreadId() (ULong)pthread_self()
   #endif
#endif

#if defined (WIN32) && defined(_DEBUG) && !defined(NO_DEBUG_TRACE)
   #include <windows.h>
#endif


static Long              g_numTraceFileCopies    = 5;
static Long              g_maxTraceFileSize      = 10000000;
static Long              g_maxOutputBeforeClose  = 4096;
static Int               g_privTraceLevel        = SEV_DEBUG;
static Int               g_sysTraceLevel         = SEV_DEBUG;
static Int               g_mailLevel             = SEV_FATAL;
static CharPtr           g_pszTraceFile          = NULL;
static time_t            g_lastTime              = time(NULL);
static Long              g_delaySameMessage      = 2;
static Int               g_lastSame              = 0;
static CharPtr           g_pszLastMessage        = NULL;
static Int               g_lastFileId            = -1;
static RefCounter*       g_pFileCount            = NULL;
static SeverityCode      g_lastSevCode           = SEV_ERROR;
static CharPtr           g_pszLastSourceFile     = NULL;
static Int               g_lastLineNo            = -1;
static TraceFile**       g_fileArr               = NULL;
static Int               g_fileArrAlloc          = 0;
static Int               g_fileArrFilled         = 0;
static CriticalSection*  g_pcs                   = NULL;
static ULong*            g_threadArr             = NULL;
static Int               g_threadArrAlloc        = 0;
static Int               g_threadArrFilled       = 0;
static ULong             g_threadId              = 0;
static Char              g_szThreadIdChars[]     = " 1234567890ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz";

static CharPtr           g_sevTextArr[]          =
    { "SYSINFO", "DEBUG  ", "INFO   ", "HINT   ", "WARNING", "ERROR  ", "FATAL  " };

//////////////////////////////////////////////////////////////////////////
//
// class TraceFile
//
//////////////////////////////////////////////////////////////////////////

// the destructor searches for its own TraceFile object and removes it
// from global array
TraceFile::~TraceFile()
{
   delete [] m_pFileName;

   Int i;
   // loop all TraceFile objects
   for (i = 0; i < g_fileArrFilled; i++)
   {
      if (g_fileArr[i] == this)
      {
          g_fileArrFilled--;
          // shift the rest of the array one position left
          for ( ; i < g_fileArrFilled; i++)
             g_fileArr[i] = g_fileArr[i+1];
       break;
      }
   }
   // loop all threads
   for (i = 0; i < g_threadArrFilled; i++)
   {
      if (g_threadArr[i] == getThreadId())
      {
          g_threadArrFilled--;
          // shift the rest of the array one position left
          for ( ; i < g_threadArrFilled; i++)
             g_threadArr[i] = g_threadArr[i+1];
          break;
      }
   }
   if (g_fileArrFilled == 0)
   {
      delete g_pFileCount;
      g_pFileCount = NULL;

      if (g_threadArr != NULL)
      {
           delete [] g_threadArr;
           g_threadArr       = NULL;
           g_threadArrFilled = 0;
           g_threadArrAlloc  = 0;
      }
   }
}

// get and increase global counter for TraceFile objects
Int TraceFile::getNewId()
{
   if (g_pFileCount == NULL)
      g_pFileCount = new RefCounter;
   return ++(*g_pFileCount);
}

// open trace file and insert TraceFile object to global array
Bool TraceFile::open(ConstCharPtr pFileName)
{
   if (m_bOpen)
      return True;

   // check if file exists and set no of filled bytes
   struct stat status;
   if (String::stringCompare(pFileName, -1, "stderr", -1) == EQUAL)
   {
      m_bStdErr = True;
      m_filled  = 0;
   }
   else if (stat(pFileName, &status) == 0)
      m_filled = status.st_size;
   else
      m_filled = 0;

   if (!m_bStdErr)
   {
      // open file in append mode
      Int mode = ios::out | ios::app;
      m_of.open(pFileName, mode);
      if (m_of.fail())
     return False;
   }

   // fill members
   m_pFileName = String::copyBuffer(m_pFileName, pFileName);
   m_fileId    = getNewId();

   // create array of TraceFile objects if first approach
   if (g_fileArr == NULL)
   {
      g_fileArr         = new TraceFile*[10];
      g_fileArrAlloc    = 10;
      g_fileArrFilled   = 0;
   }
   // increase array if full
   else if (g_fileArrFilled >= g_fileArrAlloc)
   {
      g_fileArrAlloc += 10;
      TraceFile** newArr = new TraceFile*[g_fileArrAlloc];
      for (Int i = 0; i < g_fileArrFilled; i++)
       newArr[i] = g_fileArr[i];
      delete [] g_fileArr;
      g_fileArr = newArr;
   }
   // insert this object at end of array
   g_fileArr[g_fileArrFilled++] = this;
   return m_bOpen = True;
}

// close and open trace file to free the internal file buffers
Bool TraceFile::reopen()
{
   if (isStdErr())
      return False;

   if (isOpen())
      close();

   // open file in append mode
   Int mode = ios::out | ios::app;
   m_of.open(m_pFileName, mode /*, PROT_SH_READ | PROT_SH_WRITE */);
   if (m_of.fail())
      return False;

   return m_bOpen = True;
}

// shift operator: writes to trace file
TraceFile& TraceFile::operator << (ConstCharPtr str)
{
   if (!m_bOpen)
      return *this;


   // get length of new output and increase byte counter
   Int nAdd  = String::stringLength(str) + 1;
   m_filled += nAdd;

   // if maximum trace file size is reached  we try to rename the old
   // file and get a new empty one
   if (m_filled % g_maxTraceFileSize < nAdd)
   {
      if (getNewTraceFileVersion())
       m_filled = nAdd;
   }
   if (m_bStdErr)
      cerr << str;
   else
   {
      m_of << str;
      // close and open file again to release all stream buffers
      if (m_filled % g_maxOutputBeforeClose < nAdd)
     reopen();
   }
   return *this;
}

// shift operator: writes to trace file
TraceFile& TraceFile::operator << (Char c)
{
   if (!m_bOpen)
      return *this;


   // increase byte counter
   m_filled++;

   // if maximum trace file size is reached  we try to rename the old
   // file and get a new empty one
   if (m_filled % g_maxTraceFileSize < 1)
   {
      if (getNewTraceFileVersion())
       m_filled = 1;
   }
   if (m_bStdErr)
      cerr << c;
   else
      m_of << c;
   return *this;
}

// overload of shift operator which takes an ostream function
// such as endl or ends as an argument
TraceFile& TraceFile::operator <<(ostream& (* _f)(ostream&))
{
   if (m_bStdErr)
      cerr << _f;
   else
      m_of << _f;

   return *this;
}

// close the file
void TraceFile::close()
{
   if (m_bOpen)
   {
      if (!m_bStdErr)
       m_of.close();
      m_bOpen = False;
   }
}

// check no of old file versions having a version no as extension
// if the maximum no of files to keep is reached, the oldest
// gets deleted and all others will be renamed to one version less
// e.g. tracefil.9 -> tracefil.8 and so on
Bool TraceFile::getNewTraceFileVersion()
{
   // find out if a max 3-bytes extension can be replaced by a number
   Int      nLen        = String::stringLength(m_pFileName);
   Int      nDot        = nLen;
   while (--nDot >= 0)
      if (m_pFileName[nDot] == ('.'))
     break;

   // the file extension gets replaced if the original file has
   // already an extension which is not longer than 3 bytes and
   // the maximal no of versions has a maximum of 3 digits
   Bool bReplExt = nDot >= nLen - 4 && nDot > 0 && g_numTraceFileCopies < 1000;
   Char szFileName[BAS_MAX_PATH + 1];

   if (bReplExt)
   {
      // get a local copy
      String::copyString(szFileName, m_pFileName, nDot + 1);
      // set string length one byte after the dot
      szFileName[nDot+1] = '\0';
      nLen = nDot+1;
   }
   // if the file has no max 3-bytes extension
   // we add the version extension to original filename
   else
   {
      // get a local copy of the whole file
      String::copyString(szFileName, m_pFileName, nLen);
      // add dot and set new length
      szFileName[nDot+1] = '.';
      szFileName[nDot+2] = '\0';
      nLen++;
   }

   // check if old versions exist
   Int            i = 1;
   // Char        szFile[BAS_MAX_PATH];
   String         strFile;
   ostringstream  fileStream; // (szFile, BAS_MAX_PATH);
   struct stat    fileInfo;
   Int            nVersions   = 0;
   Int            nextVersion = 1;

   // the no of files to keep is in g_numTraceFileCopies
   for (i = 1; i <= g_numTraceFileCopies; i++)
   {
      // we make the concatination by stream operation
      fileStream.seekp(0);
      fileStream << szFileName << i; //  << ends;
      strFile = fileStream.str().c_str();
      // if file doesn't exist we are thru
      if (stat(strFile, &fileInfo) != 0)
          break;
      nVersions++;
   }
   // if we hold the maximum no of versions
   // we delete the file with extension .1
   // and rename all others to the next lower number.
   // if an error occurs (maybe because one of the files is in the editor)
   // the function returns FALSE which means that the original file will
   // be used again
   if (nVersions >= g_numTraceFileCopies)
   {
      // delete <tracefile>.1
      fileStream.seekp(0);
      fileStream << szFileName << 1; // << ends;
      if (remove(strFile) == 0)
      {
     // rename the rest
     Char szFileRen[BAS_MAX_PATH];
     for (i = 1; i < g_numTraceFileCopies; i++)
     {
        fileStream.seekp(0);
        fileStream << szFileName << i+1; // << ends;
        String::copyString(szFileRen, strFile);
        fileStream.seekp(0);
        fileStream << szFileName << i;
        strFile = fileStream.str().c_str();
        if (rename(szFileRen, strFile) != 0)
        {
           if (errno == ENOENT)
              break;
           return False;
        }
     }
      }
      else if (errno != ENOENT)
          return False;
      nextVersion = g_numTraceFileCopies;
   }
   else
      nextVersion = nVersions + 1;

   // close the current file
   close();

   // rename to next version no
   fileStream.seekp(0);
   fileStream << szFileName << nextVersion;
   strFile = fileStream.str().c_str();
   if (rename(m_pFileName, strFile) != 0)
   {
      m_of.open(m_pFileName);

      return m_of.fail()? True : False;
   }

   // open the file again (create a new one)
   m_of.open(m_pFileName /*, ios::noreplace | ios::out */);
   if (m_of.fail())
      return False;
   return m_bOpen = True;
}

// find trace file by filename
TraceFile* TraceFile::getTraceFile(ConstCharPtr pFileName)
{
   for (Int i = 0; i < g_fileArrFilled; i++)
   {
      if (String::stringCompare(pFileName, -1, g_fileArr[i]->getFileName(), -1) == EQUAL)
      {
          return g_fileArr[i];
      }
   }
   return NULL;
}

// do the tracing: this call will be encapsulated in macros because of
// use of __FILE__ and __LINE__ and the casting of the ostringstream argument
Bool TraceFile::trace(ConstCharPtr pszSourceFile, Int lineNo, ostringstream& osText,
              SeverityCode sevCode, ConstCharPtr pszTraceFileName)
{
   if (g_pcs == NULL)
      g_pcs = new CriticalSection;

   g_pcs->enter();        //

   if (g_pszTraceFile == NULL)
   {
      g_pszTraceFile = new Char[sizeof("stderr") + 1];
      String::copyString(g_pszTraceFile, "stderr");
   }

   // find out if system or private trace file and get local copy of tracefile name
   Char pszTraceFile[BAS_MAX_PATH];
   Bool bPrivate  = True;
   Int  nLen      = String::stringLength(pszTraceFileName);

   if (nLen == 0 || String::stringCompare(pszTraceFileName, nLen, g_pszTraceFile, -1) == EQUAL)
   {
      String::copyString(pszTraceFile, g_pszTraceFile);
      bPrivate  = False;
   }
   else
      String::copyString(pszTraceFile, pszTraceFileName);

   // ignore trace if severity is less than the current settings
   if (sevCode != SEV_SYSINFO && sevCode != SEV_NONE)
   {
      if ((bPrivate  && sevCode < g_privTraceLevel) ||
          (!bPrivate && sevCode < g_sysTraceLevel))
      {
          g_pcs->leave();
          return False;
      }
   }

   // get TraceFile object: first we try to get an existing one
   TraceFile* pFile = TraceFile::getTraceFile(pszTraceFile);
   if (pFile == NULL)
   {
      // get a new file
      pFile = new TraceFile;
      // if open goes wrong no trace is written
      pFile->open(pszTraceFile);
   }
   else if (!pFile->isOpen())
   {
      pFile->reopen();
   }

   if (!pFile->isOpen())
   {
      // !!todo!!
      // send operator mail because of bad trace file
      g_pcs->leave();
      return False;
   }

   // get character to identify different threads
   ULong threadId = getThreadId();
   Int   i        = 0;
   for (i = 0; i < g_threadArrFilled; i++)
   {
      if (g_threadArr[i] == threadId)
       break;
   }
   if (i == g_threadArrFilled)
   {
      if (g_threadArr == NULL)
      {
          g_threadArr       = new ULong[10];
          g_threadArrAlloc  = 10;
      }
      else if (g_threadArrFilled == g_threadArrAlloc)
      {
          delete [] g_threadArr;
          g_threadArrAlloc += 10;
          g_threadArr       = new ULong[g_threadArrAlloc];
      }
      g_threadArr[g_threadArrFilled++] = threadId;
   }
   Char cThread = g_szThreadIdChars[i % (sizeof(g_szThreadIdChars) - 1)];

   // put zero byte at end of stream to get a valid string
   // osText << ends;
   ConstCharPtr text = osText.str().c_str();
   // osText.rdbuf()->freeze(0);
   nLen  = strlen(text);

   // we need a local string stream to format the output
   ostringstream os;
   // get current time in clock ticks
   time_t curTime = time(NULL);
   // compute time difference in seconds since last message
   time_t elapsed  = (curTime - g_lastTime);

   // check if last message is repeated (check the 'cheapest' conditions first)
   if (sevCode != SEV_NONE &&                                                          // no same line outputs
       g_lastLineNo == lineNo &&                                                       // same line no
       pFile->getFileId()  == g_lastFileId &&                                          // same trace file
       g_threadId == threadId &&                                                       // same thread
       g_pszLastMessage != NULL &&                                                     // not the first approach
       String::stringCompare(text, nLen, g_pszLastMessage, -1) == EQUAL &&             // same message text
       String::stringCompare(g_pszLastSourceFile, -1, pszSourceFile, -1) == EQUAL      // same source file
      )
   {
      g_lastSame++;
      // if less than configured the message is suppressed
      if (elapsed < g_delaySameMessage)
      {
          g_pcs->leave();
          return False;
      }
      if (g_lastSame > 2)
       // ... otherwise the last message is shown again
          pFile->out((ostringstream&)(os << "NEXT MESSAGE REPEATED " << g_lastSame-1 << " TIMES"),
               SEV_SYSINFO, g_pszLastSourceFile, g_lastLineNo);
   }
   // a new message! check if we have to show an old message buffered
   else if (g_lastSame > 1)
   {
// todo: the next statement has to activated again if it has cleared where some illegal
//       duplicate messages come from
//      if (g_lastSame > 2)
     pFile->out((ostringstream&)(os << "NEXT MESSAGE REPEATED " << g_lastSame - 1 << " TIMES"),
            SEV_SYSINFO, g_pszLastSourceFile, g_lastLineNo);
      pFile->out((ostringstream&)(os << g_pszLastMessage), g_lastSevCode, g_pszLastSourceFile, g_lastLineNo);
   }

   // set the save values
   g_lastSame = 1;
   g_pszLastMessage     = String::copyBuffer(g_pszLastMessage, text);
   g_pszLastSourceFile  = String::copyBuffer(g_pszLastSourceFile, pszSourceFile);
   g_lastLineNo         = lineNo;
   g_lastFileId         = pFile->getFileId();
   g_lastSevCode        = sevCode;
   g_lastTime           = curTime;
   g_threadId           = threadId;

   // write message to file
   pFile->out(osText, sevCode, pszSourceFile, lineNo, cThread);

   g_pcs->leave();
   return True;
}

// format a message and write it to file
void TraceFile::out(ostringstream& os, SeverityCode sevCode, ConstCharPtr pszSourceFile, Int lineNo, Char cThread)
{
   if (sevCode != SEV_NONE)
   {
       DateTime stamp(DTS_TIMESTAMP);
       String   strStamp = stamp.getTimeStampInt('\0', ' ', '\0', '.');
       // write timestamp and severity code
       *this << cThread << ' ' << strStamp.getText() << " " << g_sevTextArr[sevCode];

       // extract filename from path
       Int nPos = String::stringLength(pszSourceFile);

       if (nPos > 0)
       {
           Int nLen = nPos;
           while (nPos > 0)
           {
              if (pszSourceFile[nPos-1] == '/' || pszSourceFile[nPos-1] == '\\')
             break;
              nPos--;
           }

           // calculate new length
           nLen -= nPos;

           // convert line no to string by means of ostream
           ostringstream oss;
           oss << "[" << lineNo << "]";
           for (Int i = nLen + oss.str().length(); i < 20; i++)
              oss << ' ';
           // oss << ends;

           // write source file and line number
           *this << " "  << &pszSourceFile[nPos] << oss.str().c_str();
       }
   }

   // set zero byte at end and get zero sized string from ostringstream
   // os << ends;
   ConstCharPtr  pc = os.str().c_str();
   // os.rdbuf()->freeze(0);

   // write message and flush
   if (sevCode != SEV_NONE)
       *this << pc << endl;
   else
       *this << pc;

#if defined(WIN32) && defined(_DEBUG)  && !defined(NO_DEBUG_TRACE)
   // put trace message to output window of (Visual C++) debugger
   int      len  = strlen(pc);
   // CharPtr  pBuf = new Char[len + 10];
   ostringstream osd;
   osd << osd.str().c_str() << '\n';
   OutputDebugString(osd.str().c_str());
   // delete [] pBuf;
#endif

   // reset strstream to begin
   os.seekp(0);
}

// close and delete all registered trace files;
// write closing message to file
void TraceFile::removeAll()
{
   Int i;
   for (i = g_fileArrFilled - 1; i >= 0; i--)
   {
      delete g_fileArr[i];
   }
   delete [] g_fileArr;
   g_fileArr = NULL;
   g_fileArrFilled = 0;
   g_fileArrAlloc  = 0;

   delete [] g_threadArr;
   g_threadArr = NULL;
   g_threadArrFilled = 0;
   g_threadArrAlloc  = 0;

   delete [] g_pszTraceFile;
   g_pszTraceFile = NULL;
   delete [] g_pszLastMessage;
   g_pszLastMessage = NULL;
   delete g_pFileCount;
   g_pFileCount = NULL;
   delete [] g_pszLastSourceFile;
   g_pszLastSourceFile = NULL;
   delete g_pcs;
   g_pcs = NULL;
}

// called from function check(), which makes argument checking and call
// this member if the condition fails
// a trace is written to system trace file and the process will be aborted
void TraceFile::traceConditionFailure(ConstCharPtr pMessage, ConstCharPtr pCondition, Int bCond, ConstCharPtr file, Int line)
{
   ostringstream os;
   trace(file, line, (ostringstream&)(os << pMessage << pCondition << " [" << bCond << "]"), SEV_FATAL);
   abort();
}

// close a registered trace file
void TraceFile::close(ConstCharPtr pszTraceFile)
{
   // get TraceFile object by name and close it
   TraceFile* pFile = TraceFile::getTraceFile(pszTraceFile);
   if (pFile != NULL && pFile->isOpen())
      pFile->close();
}



/*****************************************************************************/
/*                           Module initialization                           */
/*****************************************************************************/



// @func
// Initialize the trace module.
void initTrace (const char* traceFileName)
{
   if (g_pcs == NULL)
      g_pcs = new CriticalSection;

   g_pcs->enter();        //

   if (g_pszTraceFile != NULL)
   {
      delete [] g_pszTraceFile;
      g_pszTraceFile = NULL;
   }

   // Read the filename for the log file from the configuration
   g_pszTraceFile = strdup (traceFileName);

   // Use the trace module to log fatal errors
   g_CheckFailed = TraceFile::traceConditionFailure;

   g_pcs->leave();        //
}


0
 
LVL 30

Author Comment

by:Axter
ID: 12724973
>>It has to be a static class member or it would work only with the current Log instance. You also could use a global mutex instance or both as the following >>sample of (one of) my string class(es) shows:

I had it as a static data member already, and it still failed.

I'm going to request a deletion on this question.

To avoid this problem, I'm not TRACE in the code, and I'm just capturing the file output into a VC++ debug window.
0
 
LVL 30

Author Comment

by:Axter
ID: 12724986
FYI:
On a normal multithread program, the CMutex object does not have to be a global, static, or a data member in order for it to work.

You can use a local variable, and it will block other threads.
0
 
LVL 39

Accepted Solution

by:
itsmeandnobodyelse earned 1600 total points
ID: 12728934
>> You can use a local variable, and it will block other threads.

You have it right. Named mutexes are unique across process boundaries while unnamed are unique for one process only. But any CMutex object can be used as a local variable. That is different to CRITICAL_SECTION that i used in the samples above because these are much faster (the fastest is locking by using InterlockedIncrement).

>> TRACE(Data);  //********HANGS here

You could try two things:

1. Pass Data as const char* and convert it to CString *after* locking. The reason is that CString
    reference counting isn't thread-safe.

2. TRACE is using Windows Messages most likely passed using PostMessage. That method isn't
    thread-safe either as CString already could be deleted before. You could either call Sleep(..)
    after TRACE to give more time or - maybe better - use a circular queue to hold last ten log
    messages.

Regards, Alex
0
 
LVL 30

Author Comment

by:Axter
ID: 12729084
>>Pass Data as const char* and convert it to CString *after* locking. The reason is that CString '
>>    reference counting isn't thread-safe.

That sounds promising.

If I have a requirement to put the TRACE logic back into the code, I'll try that.

Thank you all.
0
 
LVL 39

Expert Comment

by:itsmeandnobodyelse
ID: 12729237
>> Windows Messages most likely passed using PostMessage

That statement might be wrong, *but* Windows Messaging itself isn't thread-safe if the threads don't use an own Message Queue as it is done by CWinThread.

Regards, Alex
0

Featured Post

New feature and membership benefit!

New feature! Upgrade and increase expert visibility of your issues with Priority Questions.

Question has a verified solution.

If you are experiencing a similar issue, please ask a related question

Introduction: Finishing the grid – keyboard support for arrow keys to manoeuvre, entering the numbers.  The PreTranslateMessage function is to be used to intercept and respond to keyboard events. Continuing from the fourth article about sudoku. …
Have you tried to learn about Unicode, UTF-8, and multibyte text encoding and all the articles are just too "academic" or too technical? This article aims to make the whole topic easy for just about anyone to understand.
This video will show you how to get GIT to work in Eclipse.   It will walk you through how to install the EGit plugin in eclipse and how to checkout an existing repository.
Are you ready to place your question in front of subject-matter experts for more timely responses? With the release of Priority Question, Premium Members, Team Accounts and Qualified Experts can now identify the emergent level of their issue, signal…
Suggested Courses
Course of the Month20 days, 8 hours left to enroll

868 members asked questions and received personalized solutions in the past 7 days.

Join the community of 500,000 technology professionals and ask your questions.

Join & Ask a Question