{"id":188,"date":"2007-01-25T11:03:14","date_gmt":"2007-01-25T09:03:14","guid":{"rendered":"https:\/\/alax.info\/blog\/188"},"modified":"2007-01-25T11:03:14","modified_gmt":"2007-01-25T09:03:14","slug":"how-to-print-function-names-to-debug-output-with-atls-atltrace-macro","status":"publish","type":"post","link":"https:\/\/alax.info\/blog\/188","title":{"rendered":"How to print function names to debug output with ATL’s ATLTRACE macro"},"content":{"rendered":"

Starting Visual Studio .NET version 2003 (2002?) ATL offered new tracing macros ATLTRACE\/ATLTRACE2<\/a> which are quite convenient and flexible to generate debug output and, what is important, come with ATL debug API which allows to adjust output settings on runtime using ATL\/MFC Trace Tool<\/a>.<\/p>\n

The problem however appeared to be that ATL debug API does not seem to support printing function names, although trace tools shows checbox “Category & Function Names”. I am solving this shortage.<\/p>\n

<\/p>\n

The way to solve the problem is in updating ATL source code, atltrace.h<\/em> file. One can either modify the file in ATL include directory, or, the way I prefer, is to make a copy of the file, update it and include before other ATL includes to include instead of original header file. There will be no updated file because it is based on ATL code which, I believe, requires special permission to distribute. Changes are mentioned below though.
\nFirst of all, at the very top, a replacement header file requires definition of __ATLTRACE_H__<\/strong> to prevent from inclusion of original atltrace.h<\/em>:<\/p>\n

#define __ATLTRACE_H__ \/\/ This is a replacement of ATL’s atltrace.h<\/em><\/p><\/blockquote>\n

Then we definitely have to update ATLRACE and ATLTRACE2 macro definition to involve function name __FUNCTION__<\/strong><\/a>:<\/p>\n

#define ATLTRACE ATL::CTraceFileLineFunctionInfo(__FILE__, __LINE__, __FUNCTION__)
\n#define ATLTRACE2 ATLTRACE<\/em><\/p><\/blockquote>\n

CTraceFileLineFunctionInfo is a new class based on original CTraceFileAndLineInfo to also involve __FUNCTION__ parameter and pass it through the calls to ATL::CTrace::s_trace.TraceV, which in its turn also needs an extra parameter to be added.<\/p>\n

TraceV uses ATL debug API AtlTraceVA<\/em>\/AtlTraceVU<\/em> call to actually print debug output. It does not show us a parameter for function name, so we have to inject it before variable list of arguments. Updated TraceV is shown below (WCHAR version is updated correspondingly):<\/p>\n

inline VOID __cdecl CTrace::TraceV(LPCSTR pszFileName, INT nLine, LPCSTR pszFunctionName, DWORD_PTR nCategory, UINT nLevel, LPCSTR pszFormat, va_list Arguments) const
\n{
\n#if defined(_DEBUG)
\nCHAR pszFormatEx[4096] = { 0 };
\nstrcpy_s(pszFormatEx, _countof(pszFormatEx), “%hs: “);
\nstrcat_s(pszFormatEx, _countof(pszFormatEx), pszFormat);
\nstruct { LPCSTR pszFunctionName; BYTE pnBuffer[1024 – sizeof (LPCSTR)]; } ArgumentsEx;
\nArgumentsEx.pszFunctionName = pszFunctionName;
\nif(Arguments)
\n{
\nSIZE_T nArgumentsSize = ATL::GetTraceArgumentsSize(pszFormat, Arguments);
\nATLASSERT(!IsBadReadPtr(Arguments, nArgumentsSize));
\nATLASSERT(nArgumentsSize <= sizeof ArgumentsEx.pnBuffer);\nCopyMemory(ArgumentsEx.pnBuffer, Arguments, nArgumentsSize);\n}\nAtlTraceVA(m_nModule, pszFileName ? strrchr(pszFileName, '\\\\') + 1 : pszFileName, nLine, nCategory, nLevel, pszFormatEx, (va_list) &ArgumentsEx);\n#else\npszFunctionName;\nAtlTraceVA(m_nModule, pszFileName, nLine, nCategory, nLevel, pszFormat, Arguments);\n#endif \/\/ defined(_DEBUG)\n}<\/em><\/p><\/blockquote>\n

To print function names in front of debug output we are inserting “%hs: “<\/em> format before the provided pszFormat<\/em> and we also need to insert an LPCSTR<\/em> pointer into the beginning of variable argument list Arguments<\/em>. We need to find list size, for simplicity (unexact) it can be obtained using the following function GetTraceArgumentsSize<\/em>:<\/p>\n

inline SIZE_T GetTraceArgumentsSize(LPCSTR pszFormat, va_list Arguments)
\n{
\nSIZE_T nSize = 8 * sizeof (BYTE*);
\nif(pszFormat)
\nfor(LPCSTR pszPointer = pszFormat; ; )
\n{
\nLPCSTR pszOccurrence = strchr(pszPointer, ‘%’);
\nif(!pszOccurrence)
\nbreak;
\nnSize += sizeof (BYTE*);
\npszPointer = pszOccurrence + 1;
\n}
\nreturn nSize;
\n}<\/em><\/p><\/blockquote>\n

In order to not flood output with file paths, strrchr<\/em> is used to strip source file directory and print file name only. It does not appear to be a problem with Visual Studio .NET IDE to remain lines clickable and navigating to source code position.<\/p>\n

Update complete? Yes:<\/p>\n

application.h(424) : atlTraceGeneral: CApplication::Start<\/strong>: …
\naiatlcom.h(651) : atlTraceGeneral: CThreadT::Initialize<\/strong>: Thread 4828 (0x12dc) has been started from thread 2984
\naiatlcom.h(588) : atlTraceGeneral: CThreadT::ThreadProc<\/strong>: Thread 4828 (0x12dc) has been started<\/em><\/p><\/blockquote>\n

Function names are in debug output now. Very convenient!<\/p>\n","protected":false},"excerpt":{"rendered":"

Starting Visual Studio .NET version 2003 (2002?) ATL offered new tracing macros ATLTRACE\/ATLTRACE2 which are quite convenient and flexible to generate debug output and, what is important, come with ATL debug API which allows to adjust output settings on runtime using ATL\/MFC Trace Tool. The problem however appeared to be that ATL debug API does… <\/p>\n

Read the full article<\/a><\/p>\n","protected":false},"author":2,"featured_media":0,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[11],"tags":[],"class_list":["post-188","post","type-post","status-publish","format-standard","hentry","category-atl"],"_links":{"self":[{"href":"https:\/\/alax.info\/blog\/wp-json\/wp\/v2\/posts\/188","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/alax.info\/blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/alax.info\/blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/alax.info\/blog\/wp-json\/wp\/v2\/users\/2"}],"replies":[{"embeddable":true,"href":"https:\/\/alax.info\/blog\/wp-json\/wp\/v2\/comments?post=188"}],"version-history":[{"count":0,"href":"https:\/\/alax.info\/blog\/wp-json\/wp\/v2\/posts\/188\/revisions"}],"wp:attachment":[{"href":"https:\/\/alax.info\/blog\/wp-json\/wp\/v2\/media?parent=188"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/alax.info\/blog\/wp-json\/wp\/v2\/categories?post=188"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/alax.info\/blog\/wp-json\/wp\/v2\/tags?post=188"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}