<commit_before>/*
 * Copyright(c) Sophist Solutions, Inc. 1990-2017.  All rights reserved
 */
#include "../StroikaPreComp.h"

#include <cmath>
#include <cstdarg>
#include <cstdio>
#include <fstream>
#include <map>
#include <mutex>

#include "../Characters/CString/Utilities.h"
#include "../Characters/Format.h"
#include "../Characters/LineEndings.h"
#include "../Execution/Common.h"
#include "../Execution/Module.h"
#include "../Execution/Process.h"
#include "../Execution/Thread.h"
#include "../IO/FileSystem/PathName.h"
#include "../Memory/Common.h"
#include "../Time/Realtime.h"

#if qTraceToFile
#include "../IO/FileSystem/WellKnownLocations.h"
#include "../Time/DateTime.h"
#endif

#include "Trace.h"

using namespace Stroika::Foundation;

using namespace Characters;
using namespace Debug;
using namespace Execution;

using Execution::make_unique_lock;

/*
 * TODO:
 *
 *      @todo   The buffering code here maybe now correct, but isn't simple/clear, so rewrite/improve...
 *              -- LGP 2011-10-03
 */

CompileTimeFlagChecker_SOURCE (Stroika::Foundation::Debug, qTraceToFile, qTraceToFile);
CompileTimeFlagChecker_SOURCE (Stroika::Foundation::Debug, qDefaultTracingOn, qDefaultTracingOn);

namespace {
    // This is MOSTLY to remove NEWLINES from the MIDDLE of a message - replace with kBadChar.
    const char kBadChar_ = ' ';
    void SquishBadCharacters_ (string* s)
    {
        RequireNotNull (s);
        size_t end = s->length ();
        // ignore last 2 in case crlf
        if (end > 2) {
            end -= 2;
        }
        for (size_t i = 0; i < end; ++i) {
            if ((*s)[i] == '\n' or (*s)[i] == '\r') {
                (*s)[i] = kBadChar_;
            }
        }
    }
    void SquishBadCharacters_ (wstring* s)
    {
        RequireNotNull (s);
        size_t end = s->length ();
        // ignore last 2 in case crlf
        if (end > 2) {
            end -= 2;
        }
        for (size_t i = 0; i < end; ++i) {
            if ((*s)[i] == '\n' or (*s)[i] == '\r') {
                (*s)[i] = kBadChar_;
            }
        }
    }
}

/*
 ********************************************************************************
 ************************ Private_::TraceModuleData_ ****************************
 ********************************************************************************
 */
namespace {
    recursive_mutex* sEmitTraceCritSec_ = nullptr;
#if qTraceToFile
    ofstream* sTraceFile = nullptr;
#endif
#if qDefaultTracingOn
    thread_local unsigned int tTraceContextDepth_{0}; // no need for atomic access because thread_local
#endif

    // Declared HERE instead of the template so they get shared across TYPE values for CHARTYPE
    Thread::IDType sMainThread_ = Execution::GetCurrentThreadID ();

    string mkPrintDashAdornment_ ()
    {
        size_t threadPrintWidth = FormatThreadID_A (sMainThread_).length () - 4;
        string result;
        result.reserve (threadPrintWidth / 2);
        for (size_t i = 0; i < threadPrintWidth / 2; ++i) {
            result.append ("-");
        }
        return result;
    }
    char sThreadPrintDashAdornment_[32]; // use static array to avoid putting the string object into TraceModuleData_, and otherwise having to worry about use after main when calls DbgTrace()
    bool sDidOneTimePrimaryThreadMessage_ = false;
}

#if qTraceToFile
namespace {
    SDKString mkTraceFileName_ ()
    {
        // Use TempDir instead of EXEDir because on vista, installation permissions prevent us from (easily) writing in EXEDir.
        // (could fix of course, but I'm not sure desirable - reasonable defaults)
        //
        // Don't want to use TempFileLibrarian cuz we dont want these deleted on app exit
        SDKString mfname;
        {
            try {
                mfname = Execution::GetEXEPathT ();
            }
            catch (...) {
                mfname = SDKSTR ("{unknown}");
            }
            size_t i = mfname.rfind (IO::FileSystem::kPathComponentSeperator);
            if (i != SDKString::npos) {
                mfname = mfname.substr (i + 1);
            }
            i = mfname.rfind ('.');
            if (i != SDKString::npos) {
                mfname.erase (i);
            }
            for (auto i = mfname.begin (); i != mfname.end (); ++i) {
                if (*i == ' ') {
                    *i = '-';
                }
            }
        }
        SDKString nowstr = Time::DateTime::Now ().Format (Time::DateTime::PrintFormat::eISO8601).AsSDKString (); // use eISO8601 instead of eCurrentLocale cuz locale CTOR not safe to construct before main
        for (auto i = nowstr.begin (); i != nowstr.end (); ++i) {
            if (*i == ':') {
                *i = '-';
            }
            if (*i == '/' or *i == ' ') {
                *i = '_';
            }
        }
        return IO::FileSystem::WellKnownLocations::GetTemporaryT () + CString::Format (SDKSTR ("TraceLog_%s_PID#%d-%s.txt"), mfname.c_str (), (int)Execution::GetCurrentProcessID (), nowstr.c_str ());
    }
}
#endif

Debug::Private_::TraceModuleData_::TraceModuleData_ ()
    : fEmitter ()
    , fStringDependency (Characters::MakeModuleDependency_String ())
#if qTraceToFile
    , fTraceFileName (mkTraceFileName_ ())
#endif
{
    CString::Copy (sThreadPrintDashAdornment_, NEltsOf (sThreadPrintDashAdornment_), mkPrintDashAdornment_ ().c_str ());
    Assert (sEmitTraceCritSec_ == nullptr);
    sEmitTraceCritSec_ = new recursive_mutex ();
#if qTraceToFile
    Assert (sTraceFile == nullptr);
    sTraceFile = new ofstream ();
    sTraceFile->open (Emitter::Get ().GetTraceFileName ().c_str (), ios::out | ios::binary);
#endif
}

Debug::Private_::TraceModuleData_::~TraceModuleData_ ()
{
    delete sEmitTraceCritSec_;
    sEmitTraceCritSec_ = nullptr;
#if qTraceToFile
    AssertNotNull (sTraceFile);
    sTraceFile->close ();
    delete sTraceFile;
    sTraceFile = nullptr;
#endif
}

namespace {
    inline recursive_mutex& GetCritSection_ ()
    {
// obsolete comment because as of 2014-01-31 (or earlier) we are acutallly deleting this. But we do have
// some race where we sometimes - rarely - trigger this error. So we may need to re-instate that leak!!!
// and this comment!!!
//  --LGP 2014-02-01
#if 0
        // this is a 'false' or 'apparent' memory leak, but we allocate the object this way because in C++ things
        // can be destroyed in any order, (across OBJs), and though this gets destroyed late, its still possible
        // someone might do a trace message.
        //      -- LGP 2008-12-21
#endif
        EnsureNotNull (sEmitTraceCritSec_);
        return *sEmitTraceCritSec_;
    }
}

#if qTraceToFile
SDKString Emitter::GetTraceFileName () const
{
    return Execution::ModuleInitializer<Private_::TraceModuleData_>::Actual ().fTraceFileName;
}
#endif

#if qTraceToFile
namespace {
    void Emit2File_ (const char* text) noexcept
    {
        RequireNotNull (text);
        RequireNotNull (sTraceFile);
        try {
            if (sTraceFile->is_open ()) {
                (*sTraceFile) << text;
                sTraceFile->flush ();
            }
        }
        catch (...) {
            AssertNotReached ();
        }
    }
    void Emit2File_ (const wchar_t* text) noexcept
    {
        RequireNotNull (text);
        try {
            Emit2File_ (WideStringToUTF8 (text).c_str ());
        }
        catch (...) {
            AssertNotReached ();
        }
    }
}
#endif

/*
 ********************************************************************************
 ******************** Debug::MakeModuleDependency_Trace *************************
 ********************************************************************************
 */
Execution::ModuleDependency Debug::MakeModuleDependency_Trace ()
{
    return Execution::ModuleInitializer<Debug::Private_::TraceModuleData_>::GetDependency ();
}

/*
 ********************************************************************************
 ************************************ Emitter ***********************************
 ********************************************************************************
 */
Emitter::Emitter ()
    : fLastNCharBufCharCount_ (0)
    //  , fLastNCharBuf_CHAR_ ()
    //  , fLastNCharBuf_WCHAR_ ()
    , fLastNCharBuf_WCHARFlag_ (false)
    , fLastNCharBuf_Token_ (0)
    , fLastNCharBuf_WriteTickcount_ (0.0f)
{
}

/*
@DESCRIPTION:   <p>This function takes a 'format' argument and then any number of additional arguments - exactly
            like std::printf (). It calls std::vsprintf () internally. This can be called directly - regardless of the
             @'qDefaultTracingOn' flag - but is typically just called indirectly by calling
             @'DbgTrace'.</p>
*/
void Emitter::EmitTraceMessage (const char* format, ...) noexcept
{
    Thread::SuppressInterruptionInContext suppressAborts;
    try {
        va_list argsList;
        va_start (argsList, format);
        string tmp = Characters::CString::FormatV (format, argsList);
        va_end (argsList);
        SquishBadCharacters_ (&tmp);
        AssureHasLineTermination (&tmp);
        DoEmitMessage_ (0, Containers::Start (tmp), Containers::End (tmp));
    }
    catch (...) {
        Assert (false); // Should NEVER happen anymore becuase of new vsnprintf() stuff
        // Most likely indicates invalid format string for varargs parameters
        DoEmit_ (L"EmitTraceMessage FAILED internally (buffer overflow?)");
    }
}

void Emitter::EmitTraceMessage (const wchar_t* format, ...) noexcept
{
    Thread::SuppressInterruptionInContext suppressAborts;
    try {
        va_list argsList;
        va_start (argsList, format);
        wstring tmp = Characters::CString::FormatV (format, argsList);
        va_end (argsList);
        SquishBadCharacters_ (&tmp);
        AssureHasLineTermination (&tmp);
        DoEmitMessage_ (0, Containers::Start (tmp), Containers::End (tmp));
    }
    catch (...) {
        Assert (false); // Should NEVER happen anymore becuase of new vsnprintf() stuff
        // Most likely indicates invalid format string for varargs parameters
        DoEmit_ (L"EmitTraceMessage FAILED internally (buffer overflow?)");
    }
}

Emitter::TraceLastBufferedWriteTokenType Emitter::EmitTraceMessage (size_t bufferLastNChars, const char* format, ...) noexcept
{
    Thread::SuppressInterruptionInContext suppressAborts;
    try {
        va_list argsList;
        va_start (argsList, format);
        string tmp = Characters::CString::FormatV (format, argsList);
        va_end (argsList);
        SquishBadCharacters_ (&tmp);
        AssureHasLineTermination (&tmp);
        return DoEmitMessage_ (bufferLastNChars, Containers::Start (tmp), Containers::End (tmp));
    }
    catch (...) {
        Assert (false); // Should NEVER happen anymore becuase of new vsnprintf() stuff
        // Most likely indicates invalid format string for varargs parameters
        DoEmit_ (L"EmitTraceMessage FAILED internally (buffer overflow?)");
        return 0;
    }
}

Emitter::TraceLastBufferedWriteTokenType Emitter::EmitTraceMessage (size_t bufferLastNChars, const wchar_t* format, ...) noexcept
{
    Thread::SuppressInterruptionInContext suppressAborts;
    try {
        va_list argsList;
        va_start (argsList, format);
        wstring tmp = Characters::CString::FormatV (format, argsList);
        va_end (argsList);
        SquishBadCharacters_ (&tmp);
        AssureHasLineTermination (&tmp);
        return DoEmitMessage_ (bufferLastNChars, Containers::Start (tmp), Containers::End (tmp));
    }
    catch (...) {
        Assert (false); // Should NEVER happen anymore becuase of new vsnprintf() stuff
        // Most likely indicates invalid format string for varargs parameters
        DoEmit_ (L"EmitTraceMessage FAILED internally (buffer overflow?)");
        return 0;
    }
}

namespace {
    inline Time::DurationSecondsType GetStartOfEpoch_ ()
    {
        // factored out of template Emitter::DoEmitMessage_ so we have ONE start of epoch - instead of one per type CHARTYPE!
        static Time::DurationSecondsType sStartOfTime_ = Time::GetTickCount (); // always set just once, and threadsafe
        return sStartOfTime_;
    }
}

template <typename CHARTYPE>
Emitter::TraceLastBufferedWriteTokenType Emitter::DoEmitMessage_ (size_t bufferLastNChars, const CHARTYPE* p, const CHARTYPE* e)
{
    auto critSec{make_unique_lock (GetCritSection_ ())};
    FlushBufferedCharacters_ ();
    Time::DurationSecondsType curRelativeTime = Time::GetTickCount () - GetStartOfEpoch_ ();
    {
        char           buf[1024];
        Thread::IDType threadID    = Execution::GetCurrentThreadID ();
        string         threadIDStr = FormatThreadID_A (threadID);
        if (sMainThread_ == threadID) {
            Verify (::snprintf (buf, NEltsOf (buf), "[%sMAIN%s][%08.3f]\t", sThreadPrintDashAdornment_, sThreadPrintDashAdornment_, static_cast<double> (curRelativeTime)) > 0);
            if (not sDidOneTimePrimaryThreadMessage_) {
                sDidOneTimePrimaryThreadMessage_ = true;
                char buf2[1024];
                Verify (::snprintf (buf2, NEltsOf (buf2), "(REAL THREADID=%s)\t", threadIDStr.c_str ()) > 0);
#if __STDC_WANT_SECURE_LIB__
                strcat_s (buf, buf2);
#else
                strcat (buf, buf2);
#endif
#if qPlatform_POSIX
                Verify (::snprintf (buf2, NEltsOf (buf2), "(pthread_self=0x%lx)\t", (unsigned long)pthread_self ()) > 0);
#if __STDC_WANT_SECURE_LIB__
                strcat_s (buf, buf2);
#else
                strcat (buf, buf2);
#endif
#endif
            }
        }
        else {
            (void)::snprintf (buf, NEltsOf (buf), "[%s][%08.3f]\t", threadIDStr.c_str (), static_cast<double> (curRelativeTime));
        }
        DoEmit_ (buf);
    }
#if qDefaultTracingOn
    unsigned int contextDepth = TraceContextBumper::GetCount ();
    for (unsigned int i = 0; i < contextDepth; ++i) {
        DoEmit_ (L"\t");
    }
#endif
    if (bufferLastNChars == 0) {
        DoEmit_ (p, e);
        fLastNCharBuf_Token_++; // even if not buffering, increment, so other buffers known to be invalid
    }
    else {
        Assert ((e - p) > static_cast<ptrdiff_t> (bufferLastNChars));
        BufferNChars_ (bufferLastNChars, e - bufferLastNChars);
        DoEmit_ (p, e - bufferLastNChars);
        fLastNCharBuf_WriteTickcount_ = curRelativeTime + GetStartOfEpoch_ ();
        fLastNCharBuf_Token_++; // even if not buffering, increment, so other buffers known to be invalid
    }<commit_msg>Lose Debug/Trace GetStartOfEpoch_ () logic. Redundent since GetTickCount () now assures returns 0-based. And better to NOT do so the values reported in columsn match more exactly the GetTickCount () results.<commit_after>/*
 * Copyright(c) Sophist Solutions, Inc. 1990-2017.  All rights reserved
 */
#include "../StroikaPreComp.h"

#include <cmath>
#include <cstdarg>
#include <cstdio>
#include <fstream>
#include <map>
#include <mutex>

#include "../Characters/CString/Utilities.h"
#include "../Characters/Format.h"
#include "../Characters/LineEndings.h"
#include "../Execution/Common.h"
#include "../Execution/Module.h"
#include "../Execution/Process.h"
#include "../Execution/Thread.h"
#include "../IO/FileSystem/PathName.h"
#include "../Memory/Common.h"
#include "../Time/Realtime.h"

#if qTraceToFile
#include "../IO/FileSystem/WellKnownLocations.h"
#include "../Time/DateTime.h"
#endif

#include "Trace.h"

using namespace Stroika::Foundation;

using namespace Characters;
using namespace Debug;
using namespace Execution;

using Execution::make_unique_lock;

/*
 * TODO:
 *
 *      @todo   The buffering code here maybe now correct, but isn't simple/clear, so rewrite/improve...
 *              -- LGP 2011-10-03
 */

CompileTimeFlagChecker_SOURCE (Stroika::Foundation::Debug, qTraceToFile, qTraceToFile);
CompileTimeFlagChecker_SOURCE (Stroika::Foundation::Debug, qDefaultTracingOn, qDefaultTracingOn);

namespace {
    // This is MOSTLY to remove NEWLINES from the MIDDLE of a message - replace with kBadChar.
    const char kBadChar_ = ' ';
    void SquishBadCharacters_ (string* s)
    {
        RequireNotNull (s);
        size_t end = s->length ();
        // ignore last 2 in case crlf
        if (end > 2) {
            end -= 2;
        }
        for (size_t i = 0; i < end; ++i) {
            if ((*s)[i] == '\n' or (*s)[i] == '\r') {
                (*s)[i] = kBadChar_;
            }
        }
    }
    void SquishBadCharacters_ (wstring* s)
    {
        RequireNotNull (s);
        size_t end = s->length ();
        // ignore last 2 in case crlf
        if (end > 2) {
            end -= 2;
        }
        for (size_t i = 0; i < end; ++i) {
            if ((*s)[i] == '\n' or (*s)[i] == '\r') {
                (*s)[i] = kBadChar_;
            }
        }
    }
}

/*
 ********************************************************************************
 ************************ Private_::TraceModuleData_ ****************************
 ********************************************************************************
 */
namespace {
    recursive_mutex* sEmitTraceCritSec_ = nullptr;
#if qTraceToFile
    ofstream* sTraceFile = nullptr;
#endif
#if qDefaultTracingOn
    thread_local unsigned int tTraceContextDepth_{0}; // no need for atomic access because thread_local
#endif

    // Declared HERE instead of the template so they get shared across TYPE values for CHARTYPE
    Thread::IDType sMainThread_ = Execution::GetCurrentThreadID ();

    string mkPrintDashAdornment_ ()
    {
        size_t threadPrintWidth = FormatThreadID_A (sMainThread_).length () - 4;
        string result;
        result.reserve (threadPrintWidth / 2);
        for (size_t i = 0; i < threadPrintWidth / 2; ++i) {
            result.append ("-");
        }
        return result;
    }
    char sThreadPrintDashAdornment_[32]; // use static array to avoid putting the string object into TraceModuleData_, and otherwise having to worry about use after main when calls DbgTrace()
    bool sDidOneTimePrimaryThreadMessage_ = false;
}

#if qTraceToFile
namespace {
    SDKString mkTraceFileName_ ()
    {
        // Use TempDir instead of EXEDir because on vista, installation permissions prevent us from (easily) writing in EXEDir.
        // (could fix of course, but I'm not sure desirable - reasonable defaults)
        //
        // Don't want to use TempFileLibrarian cuz we dont want these deleted on app exit
        SDKString mfname;
        {
            try {
                mfname = Execution::GetEXEPathT ();
            }
            catch (...) {
                mfname = SDKSTR ("{unknown}");
            }
            size_t i = mfname.rfind (IO::FileSystem::kPathComponentSeperator);
            if (i != SDKString::npos) {
                mfname = mfname.substr (i + 1);
            }
            i = mfname.rfind ('.');
            if (i != SDKString::npos) {
                mfname.erase (i);
            }
            for (auto i = mfname.begin (); i != mfname.end (); ++i) {
                if (*i == ' ') {
                    *i = '-';
                }
            }
        }
        SDKString nowstr = Time::DateTime::Now ().Format (Time::DateTime::PrintFormat::eISO8601).AsSDKString (); // use eISO8601 instead of eCurrentLocale cuz locale CTOR not safe to construct before main
        for (auto i = nowstr.begin (); i != nowstr.end (); ++i) {
            if (*i == ':') {
                *i = '-';
            }
            if (*i == '/' or *i == ' ') {
                *i = '_';
            }
        }
        return IO::FileSystem::WellKnownLocations::GetTemporaryT () + CString::Format (SDKSTR ("TraceLog_%s_PID#%d-%s.txt"), mfname.c_str (), (int)Execution::GetCurrentProcessID (), nowstr.c_str ());
    }
}
#endif

Debug::Private_::TraceModuleData_::TraceModuleData_ ()
    : fEmitter ()
    , fStringDependency (Characters::MakeModuleDependency_String ())
#if qTraceToFile
    , fTraceFileName (mkTraceFileName_ ())
#endif
{
    CString::Copy (sThreadPrintDashAdornment_, NEltsOf (sThreadPrintDashAdornment_), mkPrintDashAdornment_ ().c_str ());
    Assert (sEmitTraceCritSec_ == nullptr);
    sEmitTraceCritSec_ = new recursive_mutex ();
#if qTraceToFile
    Assert (sTraceFile == nullptr);
    sTraceFile = new ofstream ();
    sTraceFile->open (Emitter::Get ().GetTraceFileName ().c_str (), ios::out | ios::binary);
#endif
}

Debug::Private_::TraceModuleData_::~TraceModuleData_ ()
{
    delete sEmitTraceCritSec_;
    sEmitTraceCritSec_ = nullptr;
#if qTraceToFile
    AssertNotNull (sTraceFile);
    sTraceFile->close ();
    delete sTraceFile;
    sTraceFile = nullptr;
#endif
}

namespace {
    inline recursive_mutex& GetCritSection_ ()
    {
// obsolete comment because as of 2014-01-31 (or earlier) we are acutallly deleting this. But we do have
// some race where we sometimes - rarely - trigger this error. So we may need to re-instate that leak!!!
// and this comment!!!
//  --LGP 2014-02-01
#if 0
        // this is a 'false' or 'apparent' memory leak, but we allocate the object this way because in C++ things
        // can be destroyed in any order, (across OBJs), and though this gets destroyed late, its still possible
        // someone might do a trace message.
        //      -- LGP 2008-12-21
#endif
        EnsureNotNull (sEmitTraceCritSec_);
        return *sEmitTraceCritSec_;
    }
}

#if qTraceToFile
SDKString Emitter::GetTraceFileName () const
{
    return Execution::ModuleInitializer<Private_::TraceModuleData_>::Actual ().fTraceFileName;
}
#endif

#if qTraceToFile
namespace {
    void Emit2File_ (const char* text) noexcept
    {
        RequireNotNull (text);
        RequireNotNull (sTraceFile);
        try {
            if (sTraceFile->is_open ()) {
                (*sTraceFile) << text;
                sTraceFile->flush ();
            }
        }
        catch (...) {
            AssertNotReached ();
        }
    }
    void Emit2File_ (const wchar_t* text) noexcept
    {
        RequireNotNull (text);
        try {
            Emit2File_ (WideStringToUTF8 (text).c_str ());
        }
        catch (...) {
            AssertNotReached ();
        }
    }
}
#endif

/*
 ********************************************************************************
 ******************** Debug::MakeModuleDependency_Trace *************************
 ********************************************************************************
 */
Execution::ModuleDependency Debug::MakeModuleDependency_Trace ()
{
    return Execution::ModuleInitializer<Debug::Private_::TraceModuleData_>::GetDependency ();
}

/*
 ********************************************************************************
 ************************************ Emitter ***********************************
 ********************************************************************************
 */
Emitter::Emitter ()
    : fLastNCharBufCharCount_ (0)
    //  , fLastNCharBuf_CHAR_ ()
    //  , fLastNCharBuf_WCHAR_ ()
    , fLastNCharBuf_WCHARFlag_ (false)
    , fLastNCharBuf_Token_ (0)
    , fLastNCharBuf_WriteTickcount_ (0.0f)
{
}

/*
@DESCRIPTION:   <p>This function takes a 'format' argument and then any number of additional arguments - exactly
            like std::printf (). It calls std::vsprintf () internally. This can be called directly - regardless of the
             @'qDefaultTracingOn' flag - but is typically just called indirectly by calling
             @'DbgTrace'.</p>
*/
void Emitter::EmitTraceMessage (const char* format, ...) noexcept
{
    Thread::SuppressInterruptionInContext suppressAborts;
    try {
        va_list argsList;
        va_start (argsList, format);
        string tmp = Characters::CString::FormatV (format, argsList);
        va_end (argsList);
        SquishBadCharacters_ (&tmp);
        AssureHasLineTermination (&tmp);
        DoEmitMessage_ (0, Containers::Start (tmp), Containers::End (tmp));
    }
    catch (...) {
        Assert (false); // Should NEVER happen anymore becuase of new vsnprintf() stuff
        // Most likely indicates invalid format string for varargs parameters
        DoEmit_ (L"EmitTraceMessage FAILED internally (buffer overflow?)");
    }
}

void Emitter::EmitTraceMessage (const wchar_t* format, ...) noexcept
{
    Thread::SuppressInterruptionInContext suppressAborts;
    try {
        va_list argsList;
        va_start (argsList, format);
        wstring tmp = Characters::CString::FormatV (format, argsList);
        va_end (argsList);
        SquishBadCharacters_ (&tmp);
        AssureHasLineTermination (&tmp);
        DoEmitMessage_ (0, Containers::Start (tmp), Containers::End (tmp));
    }
    catch (...) {
        Assert (false); // Should NEVER happen anymore becuase of new vsnprintf() stuff
        // Most likely indicates invalid format string for varargs parameters
        DoEmit_ (L"EmitTraceMessage FAILED internally (buffer overflow?)");
    }
}

Emitter::TraceLastBufferedWriteTokenType Emitter::EmitTraceMessage (size_t bufferLastNChars, const char* format, ...) noexcept
{
    Thread::SuppressInterruptionInContext suppressAborts;
    try {
        va_list argsList;
        va_start (argsList, format);
        string tmp = Characters::CString::FormatV (format, argsList);
        va_end (argsList);
        SquishBadCharacters_ (&tmp);
        AssureHasLineTermination (&tmp);
        return DoEmitMessage_ (bufferLastNChars, Containers::Start (tmp), Containers::End (tmp));
    }
    catch (...) {
        Assert (false); // Should NEVER happen anymore becuase of new vsnprintf() stuff
        // Most likely indicates invalid format string for varargs parameters
        DoEmit_ (L"EmitTraceMessage FAILED internally (buffer overflow?)");
        return 0;
    }
}

Emitter::TraceLastBufferedWriteTokenType Emitter::EmitTraceMessage (size_t bufferLastNChars, const wchar_t* format, ...) noexcept
{
    Thread::SuppressInterruptionInContext suppressAborts;
    try {
        va_list argsList;
        va_start (argsList, format);
        wstring tmp = Characters::CString::FormatV (format, argsList);
        va_end (argsList);
        SquishBadCharacters_ (&tmp);
        AssureHasLineTermination (&tmp);
        return DoEmitMessage_ (bufferLastNChars, Containers::Start (tmp), Containers::End (tmp));
    }
    catch (...) {
        Assert (false); // Should NEVER happen anymore becuase of new vsnprintf() stuff
        // Most likely indicates invalid format string for varargs parameters
        DoEmit_ (L"EmitTraceMessage FAILED internally (buffer overflow?)");
        return 0;
    }
}

template <typename CHARTYPE>
Emitter::TraceLastBufferedWriteTokenType Emitter::DoEmitMessage_ (size_t bufferLastNChars, const CHARTYPE* p, const CHARTYPE* e)
{
    auto critSec{make_unique_lock (GetCritSection_ ())};
    FlushBufferedCharacters_ ();
    Time::DurationSecondsType curRelativeTime = Time::GetTickCount ();
    {
        char           buf[1024];
        Thread::IDType threadID    = Execution::GetCurrentThreadID ();
        string         threadIDStr = FormatThreadID_A (threadID);
        if (sMainThread_ == threadID) {
            Verify (::snprintf (buf, NEltsOf (buf), "[%sMAIN%s][%08.3f]\t", sThreadPrintDashAdornment_, sThreadPrintDashAdornment_, static_cast<double> (curRelativeTime)) > 0);
            if (not sDidOneTimePrimaryThreadMessage_) {
                sDidOneTimePrimaryThreadMessage_ = true;
                char buf2[1024];
                Verify (::snprintf (buf2, NEltsOf (buf2), "(REAL THREADID=%s)\t", threadIDStr.c_str ()) > 0);
#if __STDC_WANT_SECURE_LIB__
                strcat_s (buf, buf2);
#else
                strcat (buf, buf2);
#endif
#if qPlatform_POSIX
                Verify (::snprintf (buf2, NEltsOf (buf2), "(pthread_self=0x%lx)\t", (unsigned long)pthread_self ()) > 0);
#if __STDC_WANT_SECURE_LIB__
                strcat_s (buf, buf2);
#else
                strcat (buf, buf2);
#endif
#endif
            }
        }
        else {
            (void)::snprintf (buf, NEltsOf (buf), "[%s][%08.3f]\t", threadIDStr.c_str (), static_cast<double> (curRelativeTime));
        }
        DoEmit_ (buf);
    }
#if qDefaultTracingOn
    unsigned int contextDepth = TraceContextBumper::GetCount ();
    for (unsigned int i = 0; i < contextDepth; ++i) {
        DoEmit_ (L"\t");
    }
#endif
    if (bufferLastNChars == 0) {
        DoEmit_ (p, e);
        fLastNCharBuf_Token_++; // even if not buffering, increment, so other buffers known to be invalid
    }
    else {
        Assert ((e - p) > static_cast<ptrdiff_t> (bufferLastNChars));
        BufferNChars_ (bufferLastNChars, e - bufferLastNChars);
        DoEmit_ (p, e - bufferLastNChars);
        fLastNCharBuf_WriteTickcount_ = curRelativeTime;
        fLastNCharBuf_Token_++; // even if not buffering, increment, so other buffers known to be invalid
    }
{'fraction_non_alphanumeric': 0.15815972222222222, 'fraction_numerical': 0.007395833333333333, 'mean_word_length': 2.8111684530898504, 'pattern_counts': {'":': 0, '<': 43, '<?xml version=': 0, '>': 55, 'https://': 0, 'lorem ipsum': 0, 'www.': 0, 'xml': 0}, 'pii_count': 0, 'substrings_counts': 0, 'word_list_counts': {'cursed_substrings.json': 0, 'profanity_word_list.json': 0, 'sexual_word_list.json': 0, 'zh_pornsignals.json': 0}}
{'dir': 'git-commits-cleaned', 'id': '408987', 'n_tokens_mistral': 8703, 'n_tokens_neox': 8378, 'n_words': 2175}