Source code of Windows XP (NT5)
You can not select more than 25 topics Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.

600 lines
18 KiB

  1. /*==========================================================================
  2. *
  3. * Copyright (C) 1999 - 1999 Microsoft Corporation. All Rights Reserved.
  4. *
  5. * File: dndbg.c
  6. * Content: debug support for DirectPlay8
  7. *
  8. * History:
  9. * Date By Reason
  10. * ==== == ======
  11. * 05-20-99 aarono Created
  12. * 07-16-99 johnkan Fixed include of OSInd.h, defined WSPRINTF macro
  13. * 07-19-99 vanceo Explicitly declared OutStr as returning void for NT
  14. * Build environment.
  15. * 07-22-99 a-evsch Check for multiple Inits, and release CritSec when DebugPrintf
  16. * returns early.
  17. * 08-02-99 a-evsch Added LOGPF support. LW entries only go into shared-file log
  18. * 08-31-99 johnkan Removed include of <OSIND.H>
  19. * 02-17-00 rodtoll Added Memory / String validation routines
  20. * 05-23-00 RichGr IA64: Changed some DWORDs to DWORD_PTRs to make va_arg work OK.
  21. * 07-16-00 jchauvin IA64: Added %p parsing to change back to %x for Win9x machines in DebugPrintf, DebugPrintfNoLock, LogPrintf
  22. * 07-24-00 RichGr IA64: As there's no separate build for Win9x, added code to detect Win9x for the %p parse-and-replace.
  23. * 07-29-00 masonb Rewrite to add logging by subcomponent, perf improvements, process ID
  24. * 08/28/2000 masonb Voice Merge: Modified asm in DebugPrintf to preserve registers that may have affected Voice
  25. * 03/29/2001 RichGr If DPINST is defined for Performance Instrumentation, allow free build to pick up the code.
  26. *
  27. * Notes:
  28. *
  29. * Use /Oi compiler option for strlen()
  30. *
  31. ***************************************************************************/
  32. #include "dncmni.h"
  33. #include "memlog.h"
  34. #include <tchar.h>
  35. #if defined(DEBUG) || defined(DPINST)
  36. void DebugPrintfInit(void);
  37. void DebugPrintfFini(void);
  38. // The constructor of this will be called prior to DllMain and the destructor
  39. // after DllMain, so we can be assured of having the logging code properly
  40. // initialized and deinitialized for the life of the module.
  41. #ifdef DPINST
  42. #define DEBUG_BREAK() ALWAYS_BREAK()
  43. #endif
  44. struct _InitDbg
  45. {
  46. _InitDbg() { DebugPrintfInit(); }
  47. ~_InitDbg() { DebugPrintfFini(); }
  48. } DbgInited;
  49. //===============
  50. // Debug support
  51. //===============
  52. /*******************************************************************************
  53. This file contains support for the following types of logging:
  54. 1. Logging to a VXD (Win9x only)
  55. 2. Logging to a shared memory region
  56. 3. Logging to the Debug Output
  57. 4. FUTURE: Logging to a file
  58. General:
  59. ========
  60. Debug Logging and playback is designed to operate on both Win9x and
  61. Windows NT (Windows 2000). A shared file is used to capture information
  62. and can be played back using dp8log.exe.
  63. Under NT you can use the 'dt' command of NTSD to dump structures. For
  64. example:
  65. dt DIRECTPLAYOBJECT <some memory address>
  66. will show all of the members of the DIRECTPLAYOBJECT structure at the
  67. specified address. Some features are available only in post-Win2k
  68. versions of NTSD which can be obtained at http://dbg.
  69. Logging:
  70. ========
  71. Debug Logging is controlled by settings in the WIN.INI file, under
  72. the section heading [DirectPlay8]. There are several settings:
  73. debug=9
  74. controls the default debug level. All messages, at or below that debug level
  75. are printed. You can control logging by each component specified in the
  76. g_rgszSubCompName member by adding its name to the end of the 'debug' setting:
  77. debug.addr=9
  78. sets the logging level for the addressing subcomponent to 9, leaving all
  79. others at either their specified level or the level specified by 'debug'
  80. if there is no specific level specified.
  81. The second setting controls where the log is seen. If not specified, all
  82. debug logs are sent through the standard DebugPrint and will appear in a
  83. debugger if it is attached.
  84. log=0 {no debug output}
  85. log=1 {spew to console only}
  86. log=2 {spew to shared memory log only}
  87. log=3 {spew to console and shared memory log}
  88. This setting can also be divided by subcomponent, so:
  89. log=3
  90. log.protocol=2
  91. sends logs for the 'protocol' subcomponent to the shared memory log only, and
  92. all other logs to both locations.
  93. example win.ini...
  94. [DirectPlay8]
  95. Debug=7 ; lots of spew
  96. log=2 ; don't spew to debug window
  97. [DirectPlay8]
  98. Debug=0 ; only fatal errors spewed to debug window
  99. Asserts:
  100. ========
  101. Asserts are used to validate assumptions in the code. For example
  102. if you know that the variable jojo should be > 700 and are depending
  103. on it in subsequent code, you SHOULD put an assert before the code
  104. that acts on that assumption. The assert would look like:
  105. DNASSERT(jojo>700);
  106. Asserts generally will produce 3 lines of debug spew to highlight the
  107. breaking of the assumption. You can add text to your asserts by ANDing:
  108. DNASSERT(jojo>700 && "Jojo was too low");
  109. Will show the specified text when the assert occurs. For testing, you might
  110. want to set the system to break in on asserts. This is done in the
  111. [DirectPlay8] section of WIN.INI by setting BreakOnAssert=TRUE:
  112. [DirectPlay8]
  113. Debug=0
  114. BreakOnAssert=1
  115. Verbose=1
  116. The Verbose setting enables logging of file, function, and line information.
  117. Debug Breaks:
  118. =============
  119. When something really severe happens and you want the system to break in
  120. so that you can debug it later, you should put a debug break in the code
  121. path. Some people use the philosophy that all code paths must be
  122. verified by hand tracing each one in the debugger. If you abide by this
  123. you should place a DEBUG_BREAK() in every code path and remove them
  124. from the source as you trace each. When you have good coverage but
  125. some unhit paths (error conditions) you should force those paths in
  126. the debugger.
  127. Debug Logging to Shared Memory Region:
  128. ======================================
  129. All processes will share the same memory region, and will log the specified amount
  130. of activity. The log can be viewed with the DPLOG.EXE utility.
  131. Debug Logging to Debug Output:
  132. ==============================
  133. This option uses OutputDebugString to log the specified amount of activity.
  134. ==============================================================================*/
  135. #undef DPF_SUBCOMP
  136. #define DPF_SUBCOMP DN_SUBCOMP_COMMON
  137. #define ASSERT_BUFFER_SIZE 8192
  138. #define ASSERT_BANNER_STRING "************************************************************"
  139. #define ASSERT_MESSAGE_LEVEL 0
  140. #define WSPRINTF wsprintfA
  141. #define WVSPRINTF wvsprintfA
  142. #define PROF_SECT "DirectPlay8"
  143. DWORD g_dwMemLogNumEntries = 40000; // Default Num entries for MEM log, settable in win.ini
  144. DWORD g_dwMemLogLineSize = DPLOG_MAX_STRING; // Default number of bytes per log entry
  145. //
  146. // Globals for shared memory based logging
  147. //
  148. HANDLE g_hMemLogFile = 0; // NOTE: This is 0 because CreateFileMapping returns 0 on failure
  149. HANDLE g_hMemLogMutex = 0; // NOTE: This is 0 because CreateMutex returns 0 on failure
  150. PSHARED_LOG_FILE g_pMemLog = 0;
  151. BOOL g_fMemLogInited = FALSE;
  152. DWORD g_fAssertGrabMutex = FALSE;
  153. // Values for g_rgDestination
  154. #define LOG_TO_DEBUG 1
  155. #define LOG_TO_MEM 2
  156. //#define LOG_TO_FILE 4 // NOTE: Currently unused
  157. LPSTR g_rgszSubCompName[] =
  158. {
  159. "UNK", // DN_SUBCOMP_GLOBAL 0
  160. "CORE", // DN_SUBCOMP_CORE 1
  161. "ADDR", // DN_SUBCOMP_ADDR 2
  162. "LOBBY", // DN_SUBCOMP_LOBBY 3
  163. "PROTOCOL", // DN_SUBCOMP_PROTOCOL 4
  164. "VOICE", // DN_SUBCOMP_VOICE 5
  165. "DPNSVR", // DN_SUBCOMP_DPNSVR 6
  166. "WSOCK", // DN_SUBCOMP_WSOCK 7
  167. "MODEM", // DN_SUBCOMP_MODEM 8
  168. "COMMON", // DN_SUBCOMP_COMMON 9
  169. "NATHELP", // DN_SUBCOMP_NATHELP 10
  170. "TOOLS", // DN_SUBCOMP_TOOLS 11
  171. "MAX", // DN_SUBCOMP_MAX 12 // NOTE: this should never get used, but
  172. // is needed due to the way DebugPrintfInit
  173. // is written, since it reads one past the end.
  174. };
  175. #define MAX_SUBCOMPS (sizeof(g_rgszSubCompName)/sizeof(g_rgszSubCompName[0]) - 1)
  176. UINT g_rgLevel[MAX_SUBCOMPS] = {0};
  177. UINT g_rgDestination[MAX_SUBCOMPS] = {LOG_TO_DEBUG | LOG_TO_MEM};
  178. UINT g_rgBreakOnAssert[MAX_SUBCOMPS] = {1};// if non-zero, causes DEBUG_BREAK on false asserts.
  179. // if TRUE, file/line/module information is printed and logged.
  180. DWORD g_fLogFileAndLine = FALSE;
  181. // 7/24/00(RichGr) - IA64: If g_dwPlatformId == VER_PLATFORM_WIN32_WINDOWS,
  182. // we're running under Win9x.
  183. DWORD g_dwPlatformId;
  184. // Create a shared file for logging information on the fly
  185. // This support allows the current log to be dumped from the
  186. // user mode DP8LOG.EXE application. This is useful when debugging
  187. // in MSSTUDIO or in NTSD. When the DP8LOG.EXE is invoke, note that
  188. // the application will get halted until the log is completely dumped
  189. // so it is best to dump the log to a file.
  190. #undef DPF_MODNAME
  191. #define DPF_MODNAME "InitMemLogString"
  192. static BOOL InitMemLogString(VOID)
  193. {
  194. if(!g_fMemLogInited)
  195. {
  196. BOOL fInitLogFile = TRUE;
  197. if (g_dwPlatformId == VER_PLATFORM_WIN32_NT)
  198. {
  199. g_hMemLogFile = CreateFileMapping(INVALID_HANDLE_VALUE, DNGetNullDacl(), PAGE_READWRITE, 0, (DPLOG_HEADERSIZE + (DPLOG_ENTRYSIZE*g_dwMemLogNumEntries)), _T("Global\\") BASE_LOG_MEMFILENAME);
  200. }
  201. else
  202. {
  203. g_hMemLogFile = CreateFileMapping(INVALID_HANDLE_VALUE, DNGetNullDacl(), PAGE_READWRITE, 0, (DPLOG_HEADERSIZE + (DPLOG_ENTRYSIZE*g_dwMemLogNumEntries)), BASE_LOG_MEMFILENAME);
  204. }
  205. if (!g_hMemLogFile)
  206. {
  207. return FALSE;
  208. }
  209. if (GetLastError() == ERROR_ALREADY_EXISTS)
  210. {
  211. fInitLogFile = FALSE;
  212. }
  213. if (g_dwPlatformId == VER_PLATFORM_WIN32_NT)
  214. {
  215. g_hMemLogMutex = CreateMutex(DNGetNullDacl(), FALSE, _T("Global\\") BASE_LOG_MUTEXNAME);
  216. }
  217. else
  218. {
  219. g_hMemLogMutex = CreateMutex(DNGetNullDacl(), FALSE, BASE_LOG_MUTEXNAME);
  220. }
  221. if (!g_hMemLogMutex)
  222. {
  223. CloseHandle(g_hMemLogFile);
  224. g_hMemLogFile = 0;
  225. return FALSE;
  226. }
  227. g_pMemLog = (PSHARED_LOG_FILE)MapViewOfFile(g_hMemLogFile, FILE_MAP_ALL_ACCESS,0,0,0);
  228. if (!g_pMemLog)
  229. {
  230. CloseHandle(g_hMemLogMutex);
  231. g_hMemLogMutex = 0;
  232. CloseHandle(g_hMemLogFile);
  233. g_hMemLogFile = 0;
  234. return FALSE;
  235. }
  236. // NOTE: The above 3 functions do return NULL in the case of a failure,
  237. // not INVALID_HANDLE_VALUE
  238. if (fInitLogFile)
  239. {
  240. g_pMemLog->nEntries = g_dwMemLogNumEntries;
  241. g_pMemLog->cbLine = g_dwMemLogLineSize;
  242. g_pMemLog->iWrite = 0;
  243. }
  244. else
  245. {
  246. // This happens when someone before us has already created the mem log. Could be a previous DPlay instance or TestNet.
  247. g_dwMemLogNumEntries = g_pMemLog->nEntries;
  248. g_dwMemLogLineSize = g_pMemLog->cbLine;
  249. }
  250. if (g_dwMemLogNumEntries && g_dwMemLogLineSize)
  251. {
  252. g_fMemLogInited = TRUE;
  253. }
  254. }
  255. return g_fMemLogInited;
  256. }
  257. // Log a string to a shared file. This file can be dumped using the
  258. // DPLOG.EXE utility.
  259. //
  260. // dwLength does not include the '\0'
  261. //
  262. void MemLogString(LPCSTR str, size_t dwLength)
  263. {
  264. PMEMLOG_ENTRY pEntry;
  265. size_t cbCopy;
  266. // If this isn't inited, InitMemLogString failed earlier
  267. if(!g_fMemLogInited)
  268. {
  269. return;
  270. }
  271. WaitForSingleObject(g_hMemLogMutex, INFINITE);
  272. pEntry = (PMEMLOG_ENTRY)(((PUCHAR)(g_pMemLog + 1)) + (g_pMemLog->iWrite * (sizeof(MEMLOG_ENTRY) + g_dwMemLogLineSize)));
  273. g_pMemLog->iWrite = (g_pMemLog->iWrite + 1) % g_dwMemLogNumEntries;
  274. ReleaseMutex(g_hMemLogMutex);
  275. pEntry->tLogged = GETTIMESTAMP();
  276. cbCopy = dwLength + 1; // Add the terminating NULL
  277. if(cbCopy > g_dwMemLogLineSize)
  278. {
  279. cbCopy = g_dwMemLogLineSize;
  280. }
  281. memcpy(pEntry->str, str, cbCopy);
  282. pEntry->str[cbCopy-2] = '\n'; // Ensure we always end with a return
  283. pEntry->str[cbCopy-1] = '\0'; // Ensure we always NULL terminate
  284. }
  285. // DebugPrintfInit() - initialize DPF support.
  286. void DebugPrintfInit()
  287. {
  288. // Get platform information
  289. OSVERSIONINFO OSVersionInfo = {0};
  290. OSVersionInfo.dwOSVersionInfoSize = sizeof OSVersionInfo;
  291. GetVersionEx(&OSVersionInfo);
  292. g_dwPlatformId = OSVersionInfo.dwPlatformId;
  293. BOOL fUsingMemLog = FALSE;
  294. CHAR szLevel[32] = {0};
  295. strcpy(szLevel, "debug");
  296. CHAR szDest[32] = {0};
  297. strcpy(szDest, "log");
  298. CHAR szBreak[32] = {0};
  299. strcpy(szBreak, "breakonassert");
  300. // Loop through all the subcomps, and get the level and destination for each
  301. for (int iSubComp = 0; iSubComp < sizeof(g_rgszSubCompName)/sizeof(g_rgszSubCompName[0]) - 1; iSubComp++)
  302. {
  303. // NOTE: The setting under "debug" sets the default and will be used if you
  304. // don't specify settings for each subcomp
  305. g_rgLevel[iSubComp] = GetProfileIntA(PROF_SECT, szLevel, g_rgLevel[0]);
  306. g_rgDestination[iSubComp] = GetProfileIntA(PROF_SECT, szDest, g_rgDestination[0]);
  307. g_rgBreakOnAssert[iSubComp] = GetProfileIntA( PROF_SECT, szBreak, g_rgBreakOnAssert[0]);
  308. if (g_rgDestination[iSubComp] & LOG_TO_MEM)
  309. {
  310. fUsingMemLog = TRUE;
  311. }
  312. // Set up for the next subcomp
  313. strcpy(szLevel + 5, "."); // 5 is strlen of "debug", we are building debug.addr, etc.
  314. strcpy(szLevel + 6, g_rgszSubCompName[iSubComp + 1]);
  315. strcpy(szDest + 3, "."); // 3 is strlen of "log", we are building log.addr, etc.
  316. strcpy(szDest + 4, g_rgszSubCompName[iSubComp + 1]);
  317. strcpy(szBreak + 13, "."); // 13 is strlen of "breakonassert", we are building breakonassert.addr, etc.
  318. strcpy(szDest + 14, g_rgszSubCompName[iSubComp + 1]);
  319. }
  320. g_dwMemLogNumEntries = GetProfileIntA( PROF_SECT, "MemLogEntries", 40000);
  321. g_fLogFileAndLine = GetProfileIntA( PROF_SECT, "Verbose", 0);
  322. g_fAssertGrabMutex = GetProfileIntA( PROF_SECT, "AssertGrabMutex", 0);
  323. if (fUsingMemLog)
  324. {
  325. // Open the shared log file
  326. InitMemLogString();
  327. }
  328. }
  329. // DebugPrintfFini() - release resources used by DPF support.
  330. void DebugPrintfFini()
  331. {
  332. if(g_pMemLog)
  333. {
  334. UnmapViewOfFile(g_pMemLog);
  335. g_pMemLog = NULL;
  336. }
  337. if(g_hMemLogMutex)
  338. {
  339. CloseHandle(g_hMemLogMutex);
  340. g_hMemLogMutex = 0;
  341. }
  342. if(g_hMemLogFile)
  343. {
  344. CloseHandle(g_hMemLogFile);
  345. g_hMemLogFile = 0;
  346. }
  347. g_fMemLogInited = FALSE;
  348. }
  349. void DebugPrintfX(LPCSTR szFile, DWORD dwLine, LPCSTR szModName, DWORD dwSubComp, DWORD dwDetail, ...)
  350. {
  351. DNASSERT(dwSubComp < MAX_SUBCOMPS);
  352. if(g_rgLevel[dwSubComp] < dwDetail)
  353. {
  354. return;
  355. }
  356. CHAR cMsg[ ASSERT_BUFFER_SIZE ];
  357. LPSTR szFormat;
  358. char *psz = NULL;
  359. va_list argptr;
  360. LPSTR pszCursor = cMsg;
  361. va_start(argptr, dwDetail);
  362. szFormat = (LPSTR) va_arg(argptr, DWORD_PTR);
  363. cMsg[0] = 0;
  364. // IA64: If g_dwPlatformId == VER_PLATFORM_WIN32_WINDOWS,
  365. // we're running under Win9x and need to replace %p with %x.
  366. // TODO: Make this build specific, don't penalize NT
  367. if (g_dwPlatformId == VER_PLATFORM_WIN32_WINDOWS)
  368. {
  369. CHAR cTemp[ ASSERT_BUFFER_SIZE ];
  370. strcpy(cTemp, szFormat); // Copy to a local string that we can modify.
  371. szFormat = cTemp; // Point szFormat at the local string
  372. while (psz = strstr(szFormat, "%p")) // Look for each "%p".
  373. *(psz+1) = 'x'; // Substitute 'x' for 'p'. Don't try to expand
  374. }
  375. // Prints out / logs as:
  376. // 1. Verbose
  377. // subcomp:dwDetail:ProcessId:ThreadId:File:Function:Line:DebugString
  378. // e.g.
  379. // ADDR:2:0450:0378:(c:\somefile.cpp)BuildURLA(L25)Can you believe it?
  380. //
  381. // 2. Regular
  382. // subcomp:dwDetail:ProcessId:ThreadId:Function:DebugString
  383. strcpy(pszCursor, g_rgszSubCompName[dwSubComp]);
  384. pszCursor += strlen(pszCursor);
  385. pszCursor += WSPRINTF(pszCursor,":%1d:",dwDetail);
  386. pszCursor += WSPRINTF(pszCursor,"%04x:",GetCurrentProcessId());
  387. pszCursor += WSPRINTF(pszCursor,"%04x:",GetCurrentThreadId());
  388. if (g_fLogFileAndLine)
  389. {
  390. LPCSTR c;
  391. int i = strlen(szFile);
  392. if (i < 25)
  393. {
  394. c = szFile;
  395. }
  396. else
  397. {
  398. c = szFile + i - 25;
  399. }
  400. pszCursor += WSPRINTF(pszCursor,"(%s)(L%d)", c, dwLine);
  401. }
  402. pszCursor += WSPRINTF(pszCursor, "%s: ", szModName);
  403. pszCursor += WVSPRINTF(pszCursor, szFormat, argptr);
  404. strcpy(pszCursor, "\n");
  405. pszCursor += strlen(pszCursor);
  406. if(g_rgDestination[dwSubComp] & LOG_TO_DEBUG)
  407. {
  408. // log to debugger output
  409. OutputDebugStringA(cMsg);
  410. }
  411. if(g_rgDestination[dwSubComp] & LOG_TO_MEM)
  412. {
  413. // log to shared file, pass length not including '\0'
  414. MemLogString(cMsg, (DWORD) ((DWORD_PTR) (pszCursor - cMsg)));
  415. }
  416. //if(g_rgDestination[dwSubComp] & LOG_TO_FILE)
  417. //{
  418. //}
  419. va_end(argptr);
  420. return;
  421. }
  422. //
  423. // NOTE: I don't want to get into error checking for buffer overflows when
  424. // trying to issue an assertion failure message. So instead I just allocate
  425. // a buffer that is "bug enough" (I know, I know...)
  426. //
  427. void _DNAssert( LPCSTR szFile, DWORD dwLine, LPCSTR szFnName, DWORD dwSubComp, LPCSTR szCondition, DWORD dwLevel )
  428. {
  429. char buffer[ASSERT_BUFFER_SIZE];
  430. // For level 1 we always print the message to the log, but we may not actually break. For other levels
  431. // we either print and break or do neither.
  432. if (dwLevel <= g_rgBreakOnAssert[dwSubComp] || dwLevel == 1)
  433. {
  434. // Build the debug stream message
  435. WSPRINTF( buffer, "ASSERTION FAILED! File: %s Line: %d: %s", szFile, dwLine, szCondition);
  436. // Actually issue the message. These messages are considered error level
  437. // so they all go out at error level priority.
  438. DebugPrintfX(szFile, dwLine, szFnName, dwSubComp, ASSERT_MESSAGE_LEVEL, ASSERT_BANNER_STRING );
  439. DebugPrintfX(szFile, dwLine, szFnName, dwSubComp, ASSERT_MESSAGE_LEVEL, buffer );
  440. DebugPrintfX(szFile, dwLine, szFnName, dwSubComp, ASSERT_MESSAGE_LEVEL, ASSERT_BANNER_STRING );
  441. // Should we drop into the debugger?
  442. if(g_rgBreakOnAssert[dwSubComp])
  443. {
  444. // Don't let dpnsvr keep writing to the log
  445. if (g_hMemLogMutex && g_fAssertGrabMutex)
  446. {
  447. WaitForSingleObject(g_hMemLogMutex, INFINITE);
  448. }
  449. // Into the debugger we go...
  450. DEBUG_BREAK();
  451. if (g_hMemLogMutex && g_fAssertGrabMutex)
  452. {
  453. ReleaseMutex(g_hMemLogMutex);
  454. }
  455. }
  456. }
  457. }
  458. #endif //defined debug
  459. BOOL IsValidStringA( const CHAR * const szString )
  460. {
  461. return (!IsBadStringPtrA( szString, 0xFFFFFFFF ) );
  462. }
  463. BOOL IsValidStringW( const WCHAR * const swzString )
  464. {
  465. const wchar_t *szTmpLoc = swzString;
  466. if( swzString == NULL )
  467. {
  468. return FALSE;
  469. }
  470. _try
  471. {
  472. for( ; *szTmpLoc ; szTmpLoc++ );
  473. }
  474. _except( EXCEPTION_EXECUTE_HANDLER )
  475. {
  476. return FALSE;
  477. }
  478. return TRUE;
  479. }