Run-Time Check Failure #2

[majic79]

Hi - I've tried searching for a solution (or a means to find one) for my problem. I have several classes that derive from a generic "Logging" class - it allows me to easily log diagnostic output to NULL (burn the messages) or display or to file. The program is multithreaded and works fine if I don't display any debug (ie, don't call the functions below), however one particular thread seems to cause a "Run-Time Check Failure #2 - Stack around the variable sOut was corrupted" all the time. The thread is responsible to transmitting data over a serial port, and it only reports what it's currently writing to the port.

Here is are the functions, DebugOut is the function that's throwing the error, the other function is just to illustrate what DebugOut is doing (formatting the string, dropping it into a linked list and messaging the UI thread to grab data)

void CLogging::DebugOut(LPCTSTR szFmt, ...)
{
    CString sOut;
    va_list vars;

    static BOOL OnlyOnce = FALSE;
        
    while(OnlyOnce != FALSE)
        Sleep(10);

    OnlyOnce = TRUE;

    va_start(vars, szFmt);

    sOut.FormatV(szFmt, vars);
    va_end(vars);

    LogOutput(sOut);
        
    OnlyOnce = FALSE;
}

void CLogging::LogOutput(LPCTSTR szOut)
{
//  Output status message on the main window

    CSingleLock cs(&m_Crit);
    cs.Lock();
    m_sMsgList.AddTail( szOut );

    ::PostMessage(m_hWndMain,WM_DEBUGOUTPUT,0,0);
}

I added the "OnlyOnce" static var to try and eliminate a thread-reentrancy problem (just in case another thread is calling the same function - it didn't make a difference)

Any help is greatly appreciated!

[hoxsiew]

I'd think it might have something to do with the varargs list. Perhaps a UNICODE issue where the args might be MBCS and the CString is UNICODE or some other mismatch. Can you set a breakpoint and check your arguments?

[majic79]

I tried - if I set a breakpoint, it works fine, no problems. it's all set to MBCS (I've been testing with both Unicode and MBCS, has the same issue with both, but my DDE server doesn't work properly in Unicode, so I'm trying to make sure everything is fine with MBCS set before I rebuild with UNICODE)

The line of code that causes the error is:

#define SAFECHAR(c) ((((char)c) < 32 || ((char)c) == '%') ? '.' : ((char)c))

    unsigned char chr;

    char schar = SAFECHAR(chr);
    dl->DebugOut(_T("Chr xmit > 0x%02X '%c'"), chr, schar);

chr has the value 0x10 at the time of failure. (the function parses a buffer of values, writes them to the serial port and then reports what it wrote)

Full listing of the CLogging class:

// ----- Header -----------------
#pragma once


class CLogging : public CObject
{
    DECLARE_DYNCREATE(CLogging)
public:
    CLogging(void);
    ~CLogging(void);

    void SetMain(HWND hwndMain);
    void LogOutput(LPCTSTR szLine);

    CString GetLogItem();

    void DebugOut(LPCTSTR szFmt, ...);

protected:
    CCriticalSection m_Crit;
    HWND m_hWndMain;
    CStringList m_sMsgList;

    void SystemError(LPCTSTR szMessage);
};


//  ----------- Code ----------------
#include "StdAfx.h"
#include "Logging.h"


#ifdef _DEBUG
#define new DEBUG_NEW
#endif

IMPLEMENT_DYNCREATE(CLogging, CObject)

CLogging::CLogging(void) : m_sMsgList(), m_hWndMain(NULL)
{
}

CLogging::~CLogging(void)
{
    m_sMsgList.RemoveAll();
}

void CLogging::DebugOut(LPCTSTR szFmt, ...)
{
    CString sOut;
    va_list vars;

    static BOOL OnlyOnce = FALSE;
    
    while(OnlyOnce != FALSE)
        Sleep(10);

    OnlyOnce = TRUE;

    va_start(vars, szFmt);

    sOut.FormatV(szFmt, vars);
    va_end(vars);

    LogOutput((LPCTSTR)sOut.GetString());
    
    OnlyOnce = FALSE;
}

void CLogging::SetMain(HWND hwndMain)
{
    m_hWndMain = hwndMain;
}

CString CLogging::GetLogItem()
{
    CString sItem;
    if(m_sMsgList.IsEmpty()==FALSE)
    {
        CSingleLock cs(&m_Crit);
        cs.Lock();
        sItem = (LPCTSTR)m_sMsgList.RemoveHead();
        cs.Unlock();
    }
    return sItem;
}

void CLogging::SystemError(LPCTSTR szMessage)
{
    TCHAR * szFormat = _T("%s: Error %d: %s");    // format for wsprintf
    LPTSTR szError = NULL;      // error string translated from error code
    LPTSTR szFinal;         // final string to report
    DWORD dwExtSize;
    DWORD dwErr;
    DWORD dwTSize;

    dwErr = GetLastError();

    dwExtSize = FormatMessage( FORMAT_MESSAGE_FROM_SYSTEM | FORMAT_MESSAGE_ALLOCATE_BUFFER | 80 ,
                          NULL, 
                          dwErr,
                          MAKELANGID(LANG_NEUTRAL, SUBLANG_DEFAULT),
                          (LPTSTR)&szError, 
                          0, 
                          NULL);

    CString sErr;
    if (dwExtSize == 0)
    {
        szError = (LPTSTR)LocalAlloc(LMEM_ZEROINIT, sizeof(TCHAR));
        dwExtSize = 1;
    }

    dwTSize = (DWORD)_tcslen(szMessage) + dwExtSize + 40;
    szFinal = new TCHAR[dwTSize];

    if (szFinal == NULL)	// if no final buffer, then can't format error
        LogOutput(_T("Cannot properly report error!!"));
    else
    {
        _stprintf_s((LPTSTR)szFinal, dwTSize, szFormat, szMessage, dwErr, szError);
        LogOutput((LPTSTR)szFinal);
        delete[] szFinal;
    }
    LocalFree((HLOCAL)szError);

    return;
}

[hoxsiew]

Nothing strikes me as wrong with this code. The only thing I see of concern is:

    LogOutput((LPCTSTR)sOut.GetString());

and only if m_sMsgList tries to modify the buffer. What is m_sMsgList anyway? A CList? What type is passed to the CList template?

[majic79]

the only thing I do with m_sMsgList is to pull items off it as CStrings in the function GetLogItem - according to the documentation (if i read it right), you pass AddHead or AddTail a LPCTSTR and it duplicates it internally and constructs a CString

StartThread (UI thread) - Calls GetLogItem to pull a CString off the top of the list and do something with it (display it on another window) when it sees a WM_USER message (or a timer - optional, disabled at the moment)
Thread1) - Does stuff, posts output messages frequently
Thread2) - Does stuff, posts outputmessages occasionally
Thread3) - Writes to the serial line (doesn't do much else, has a syncronisation event to trigger buffer writes) - posts output messages for each char it outputs (optional - if I disable that output, the system works fine, but I can't track what the serial output is, which means I can't check for errors in my data stream)

Thread 3 is the only one that has an issue, all the other calls to DebugOut from the other work fine (I mean, they don't flag up this error)

I tried casting sOut.GetString to see if it cleared the issue (it didn't) - what I could really do with are some tips to try and track the issue down. My coding skill's are OK, my debugging skills are usually adequate, but this is one has me properly stumped

[hoxsiew]

Well, I'm at a loss. Since the stack get's corrupted "around sOut" it would seem that something is messing with sOut. The only thing I see is the call to sOut.GetString() passed to another function. Since this seems to work with other calls, then it is a mystery.

Another possibility with stack corruption is variable "near" the corrupted variable. The only candidate there is "va_list vars" (OnlyOnce is static so not on the stack) but it appears that you are using variable parameter lists correctly (and it works from other calls).

The way VC++ checks for stack corruption in debug more is to write a number of fixed values on the stack on either side of the stack variables, then check those values on function return. If they change, then something has tried to write outside its limits. A classic case is when you declare an array on the stack and write to it out-of-bounds:

int somefunction(void)
{
  int myarray[10];

  myarray[11]=10;
  return 1;
}

I don't know what else I can do to help. BTW, what is your VS version?

[majic79]

I'm using VS 2005, but I have a copy of VS2008 I supposed I could build it on.

I've re-coded the function so it doesn't call LogMessage, but does the same implementation in the DebugOut function (see code section) but now I get an ASSERT in the CSingleLock.Unlock (ASSERT(m_pObject != NULL))

void CLogging::DebugOut(LPCTSTR szFmt, ...)
{

    CSingleLock cs(&m_Crit);
    cs.Lock();
    
    {
        va_list vars;
        CString sOut;

        va_start(vars, szFmt);
        sOut.FormatV(szFmt, vars);
        va_end(vars);

        m_sMsgList.AddTail( sOut );
    
        PostMessage(m_hWndMain,WM_DEBUGOUTPUT,0,0);
    }
}

[hoxsiew]

That would indicate that m_Crit is NULL. Since it didn't ASSERT when you created your lock, or when you locked it, it must have become NULL at some point between your braces (before the DebugOut function ends thereby forcing cs out of scope which calls unlock in its destructor).

[majic79]

I think I found the problem - suitably obscure and innocuous

The thread that fails is writing data to a port - another thread is reading the port, naturally, this is done asynchronously. In my eagerness to get the program operational, I created a duff (empty) overlapped structure to satisfy the WriteFile call (file handles created with overlapped flagg must use an overlapped stucture) and after posting a single byte at a time, the function would return immediately. However, because it's overlapped, it can return before the data's sent. This week, my serial connection is being a little slow, so the error suddenly manifests itself as corruption of the stack. Guess what's pointing to the area being corrupted? My Overlapped structure in function about 2 levels down the call stack.

Anyway, I cleared up the handling of the overlapped write - create a handle, set the overlapped sturcture wait handle, if the return error is IO pending I wait for it (rather than jumping ahead and not caring - ok, it's overlapped, I've written, but I really couldn't care less, but you still have to wait for it to finish with the overlapped structure!) I wait for the return and then carry on.