1// Licensed to the .NET Foundation under one or more agreements.
2// The .NET Foundation licenses this file to you under the MIT license.
3// See the LICENSE file in the project root for more information.
4// ============================================================
5//
6// DebugLog.cpp
7//
8
9
10//
11// Implements the DebugLog class
12//
13// ============================================================
14
15#if defined(BINDER_DEBUG_LOG)
16
17#include "debuglog.hpp"
18#include "assemblyname.hpp"
19#include "utils.hpp"
20#include "variables.hpp"
21
22#include "ex.h"
23
24namespace BINDER_SPACE
25{
26 namespace
27 {
28 void GetStringFromHR(HRESULT hr,
29 SString &info)
30 {
31 switch(hr)
32 {
33 case S_OK:
34 info.Append(L"S_OK");
35 break;
36 case S_FALSE:
37 info.Append(L"S_FALSE");
38 break;
39 case E_FAIL:
40 info.Append(L"E_FAIL");
41 break;
42 case __HRESULT_FROM_WIN32(ERROR_FILE_NOT_FOUND):
43 info.Append(L"HRESULT_FROM_WIN32(ERROR_FILE_NOT_FOUND)");
44 break;
45 case __HRESULT_FROM_WIN32(ERROR_INSUFFICIENT_BUFFER):
46 info.Append(L"HRESULT_FROM_WIN32(ERROR_INSUFFICIENT_BUFFER)");
47 break;
48 case FUSION_E_REF_DEF_MISMATCH:
49 info.Append(L"FUSION_E_REF_DEF_MISMATCH");
50 break;
51 case FUSION_E_CODE_DOWNLOAD_DISABLED:
52 info.Append(L"FUSION_E_CODE_DOWNLOAD_DISABLED");
53 break;
54 default:
55 info.AppendPrintf(L"%p", hr);
56 break;
57 }
58 }
59
60 HRESULT GetLogFilePath(PathString &logFileDir,
61 PathString &logFilePath)
62 {
63 HRESULT hr = S_OK;
64
65 BOOL fFileExists = TRUE;
66
67 do
68 {
69 LARGE_INTEGER kCount1;
70 LARGE_INTEGER kCount2;
71
72 logFilePath.Clear();
73
74 if (!QueryPerformanceCounter(&kCount1))
75 {
76 hr = HRESULT_FROM_GetLastError();
77 }
78 else if(!QueryPerformanceCounter(&kCount2))
79 {
80 hr = HRESULT_FROM_GetLastError();
81 }
82 else
83 {
84 logFilePath.Printf(L"%s\\Log_%u%u_%u%u.tmp",
85 logFileDir.GetUnicode(),
86 static_cast<UINT32>(kCount1.u.LowPart),
87 kCount1.u.HighPart,
88 static_cast<UINT32>(kCount2.u.LowPart),
89 kCount2.u.HighPart);
90
91 PlatformPath(logFilePath);
92 }
93
94 fFileExists = (FileOrDirectoryExists(logFilePath) == S_OK);
95 }
96 while (fFileExists == TRUE);
97
98 return hr;
99 }
100
101 HRESULT WriteToFile(HANDLE hFile,
102 const BYTE *pbBuffer,
103 DWORD dwcbBuffer)
104 {
105 HRESULT hr = S_OK;
106 DWORD dwNumberOfBytesWritten = 0;
107
108 while ((dwcbBuffer != 0) && (dwNumberOfBytesWritten < dwcbBuffer))
109 {
110 if (WriteFile(hFile, pbBuffer, dwcbBuffer, &dwNumberOfBytesWritten, NULL))
111 {
112 dwcbBuffer -= dwNumberOfBytesWritten;
113 pbBuffer += dwNumberOfBytesWritten;
114 }
115 else
116 {
117 hr = HRESULT_FROM_GetLastError();
118 goto Exit;
119 }
120 }
121
122 Exit:
123 return hr;
124 }
125 };
126
127 /* static */
128 HRESULT DebugLog::Startup()
129 {
130 HRESULT hr = S_OK;
131
132 PathString logFileDir;
133 PathString logFilePath;
134
135 REGUTIL::CORConfigLevel kCorConfigLevel =
136 static_cast<REGUTIL::CORConfigLevel>(REGUTIL::COR_CONFIG_ENV |
137 REGUTIL::COR_CONFIG_FUSION);
138 NewArrayHolder<WCHAR> pwzLogDirectory = CLRConfig::GetConfigValue(CLRConfig::INTERNAL_CoreClrBinderLog);
139
140
141 g_BinderVariables->m_logCS = ClrCreateCriticalSection(CrstCoreCLRBinderLog, CRST_REENTRANCY);
142 if (!g_BinderVariables->m_logCS)
143 {
144 IF_FAIL_GO(E_OUTOFMEMORY);
145 }
146
147
148 if (pwzLogDirectory == NULL)
149 {
150 goto Exit;
151 }
152
153 logFileDir.Set(pwzLogDirectory);
154
155 if (WszCreateDirectory(logFileDir.GetUnicode(), NULL) ||
156 ((hr = HRESULT_FROM_GetLastError()) == HRESULT_FROM_WIN32(ERROR_ALREADY_EXISTS)))
157 {
158 hr = S_OK;
159 }
160
161 IF_FAIL_GO(GetLogFilePath(logFileDir, logFilePath));
162
163 g_BinderVariables->m_hDebugLogFile = WszCreateFile(logFilePath.GetUnicode(),
164 GENERIC_WRITE,
165 FILE_SHARE_READ,
166 NULL,
167 OPEN_ALWAYS,
168 FILE_ATTRIBUTE_NORMAL,
169 NULL);
170
171 if (g_BinderVariables->m_hDebugLogFile == INVALID_HANDLE_VALUE)
172 {
173 IF_FAIL_GO(E_FAIL);
174 }
175 Exit:
176 return hr;
177 }
178
179 // This is not multi-thread aware by any means. That said, neither is any of this logging mechanism.
180 static int s_scopeLevel = 0;
181 static const ANSI s_szScopeIndent[3] = " ";
182
183 /* static */
184 void DebugLog::Enter(WCHAR *pwzScope)
185 {
186 HRESULT hr = S_OK;
187
188 EX_TRY
189 {
190 PathString info;
191
192 info.Append(pwzScope);
193 info.Append(L": Enter");
194 Log(info);
195 }
196 EX_CATCH_HRESULT(hr);
197
198 s_scopeLevel++;
199 }
200
201 /* static */
202 void DebugLog::Leave(WCHAR *pwzScope)
203 {
204 HRESULT hr = S_OK;
205
206 s_scopeLevel--;
207
208 EX_TRY
209 {
210 PathString info;
211
212 info.Append(pwzScope);
213 info.Append(L": Leave(void)");
214 Log(info);
215 }
216 EX_CATCH_HRESULT(hr);
217 }
218
219 /* static */
220 void DebugLog::LeaveHR(WCHAR *pwzScope,
221 HRESULT hrLog)
222 {
223 HRESULT hr = S_OK;
224
225 s_scopeLevel--;
226
227 EX_TRY
228 {
229 PathString info;
230
231 info.Append(pwzScope);
232 info.Append(L": Leave(hr=");
233 GetStringFromHR(hrLog, info);
234 info.Append(L")");
235
236 Log(info);
237 }
238 EX_CATCH_HRESULT(hr);
239 }
240
241 /* static */
242 void DebugLog::LeaveBool(WCHAR *pwzScope,
243 BOOL fResult)
244 {
245 HRESULT hr = S_OK;
246
247 s_scopeLevel--;
248
249 EX_TRY
250 {
251 PathString info;
252
253 info.Append(pwzScope);
254 info.Append(L": Leave(fResult=");
255 info.Append(fResult ? L"TRUE)" : L"FALSE)");
256 Log(info);
257 }
258 EX_CATCH_HRESULT(hr);
259 }
260
261 /* static */
262 void DebugLog::Log(WCHAR *pwzComment)
263 {
264 HRESULT hr = S_OK;
265
266 EX_TRY
267 {
268 PathString info;
269
270 info.Append(pwzComment);
271 Log(info);
272 }
273 EX_CATCH_HRESULT(hr);
274 }
275
276 /* static */
277 void DebugLog::Log(WCHAR *pwzComment,
278 SString &value)
279 {
280 HRESULT hr = S_OK;
281
282 EX_TRY
283 {
284 PathString info;
285
286 info.Append(pwzComment);
287 info.Append(L" = '");
288 info.Append(value);
289 info.Append(L"'");
290
291 Log(info);
292 }
293 EX_CATCH_HRESULT(hr);
294 }
295
296 /* static */
297 void DebugLog::Log(WCHAR *pwzComment,
298 const WCHAR *value)
299 {
300 HRESULT hr = S_OK;
301
302 EX_TRY
303 {
304 PathString info;
305
306 info.Append(pwzComment);
307 info.Append(L" = '");
308 info.Append(value);
309 info.Append(L"'");
310
311 Log(info);
312 }
313 EX_CATCH_HRESULT(hr)
314 }
315
316 /* static */
317 void DebugLog::Log(WCHAR *pwzComment,
318 HRESULT hrLog)
319 {
320 HRESULT hr = S_OK;
321
322 EX_TRY
323 {
324 PathString info;
325
326 info.Append(pwzComment);
327 info.Append(L" = ");
328 GetStringFromHR(hrLog, info);
329
330 Log(info);
331 }
332 EX_CATCH_HRESULT(hr);
333 }
334
335 /* static */
336 void DebugLog::Log(WCHAR *pwzComment,
337 AssemblyName *pAssemblyName)
338 {
339 EX_TRY
340 {
341 PathString assemblyDisplayName;
342 PathString info;
343
344 if (pAssemblyName != NULL)
345 {
346 pAssemblyName->GetDisplayName(assemblyDisplayName,
347 AssemblyName::INCLUDE_VERSION |
348 AssemblyName::INCLUDE_ARCHITECTURE |
349 AssemblyName::INCLUDE_RETARGETABLE);
350 }
351 else
352 {
353 assemblyDisplayName.Set(L"<NULL>");
354 }
355
356 info.Printf(L"(%d):", static_cast<INT32>(assemblyDisplayName.GetCount()));
357 info.Append(assemblyDisplayName);
358
359 Log(pwzComment, info);
360 }
361 EX_CATCH
362 {
363 Log(L"<AssemblyDisplayName: Failure>");
364 }
365 EX_END_CATCH(SwallowAllExceptions);
366 }
367
368 /* static */
369 void DebugLog::Log(WCHAR *pwzComment,
370 void *pData)
371 {
372 HRESULT hr = S_OK;
373
374 EX_TRY
375 {
376 PathString info;
377
378 info.Append(pwzComment);
379 info.AppendPrintf(L" = %p", pData);
380 Log(info);
381 }
382 EX_CATCH_HRESULT(hr);
383 }
384
385 /* static */
386 void DebugLog::Log(SString &info)
387 {
388 HRESULT hr = S_OK;
389
390 StackScratchBuffer scratchBuffer;
391 const BYTE *pbRawBuffer = reinterpret_cast<const BYTE *>(info.GetANSI(scratchBuffer));
392 DWORD dwcbRawBuffer = static_cast<DWORD>(info.GetCount());
393 // Work around SString issue
394 const ANSI ansiCRLF[] = { 0x0d, 0x0a };
395 DWORD dwcbAnsiCRLF = 2 * sizeof(ANSI);
396 s_scopeLevel;
397 for (int iScope = 0; iScope < s_scopeLevel; iScope++)
398 {
399 IF_FAIL_GO(WriteToFile(g_BinderVariables->m_hDebugLogFile, reinterpret_cast<const BYTE *>(&s_szScopeIndent[0]), sizeof(s_szScopeIndent)));
400 }
401 IF_FAIL_GO(WriteToFile(g_BinderVariables->m_hDebugLogFile, pbRawBuffer, dwcbRawBuffer));
402 IF_FAIL_GO(WriteToFile(g_BinderVariables->m_hDebugLogFile,
403 reinterpret_cast<const BYTE *>(ansiCRLF),
404 dwcbAnsiCRLF));
405 // Don't cache anything
406 if (!FlushFileBuffers(g_BinderVariables->m_hDebugLogFile))
407 {
408 WszOutputDebugString(L"DebugLog::Log(info): FlushFileBuffers failed!\n");
409 }
410
411 Exit:
412 return;
413 }
414};
415
416#endif
417