src/binder/debuglog.cpp

   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
  24 namespace 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