diff --git a/src/AspNetCoreModuleV1/AspNetCore/aspnetcoremodule.rc b/src/AspNetCoreModuleV1/AspNetCore/aspnetcoremodule.rc index 7790f5067f..2e4ee7c0f9 100644 --- a/src/AspNetCoreModuleV1/AspNetCore/aspnetcoremodule.rc +++ b/src/AspNetCoreModuleV1/AspNetCore/aspnetcoremodule.rc @@ -10,7 +10,7 @@ #if !defined(AFX_RESOURCE_DLL) || defined(AFX_TARG_ENU) LANGUAGE LANG_ENGLISH, SUBLANG_ENGLISH_US -#define FileDescription "IIS AspNetCore Module. Commit: " CommitHash +#define FileDescription "IIS ASP.NET Core Module. Commit: " CommitHash ///////////////////////////////////////////////////////////////////////////// // diff --git a/src/AspNetCoreModuleV2/AspNetCore/aspnetcoremodule.rc b/src/AspNetCoreModuleV2/AspNetCore/aspnetcoremodule.rc index f9acf89035..9a110e2920 100644 --- a/src/AspNetCoreModuleV2/AspNetCore/aspnetcoremodule.rc +++ b/src/AspNetCoreModuleV2/AspNetCore/aspnetcoremodule.rc @@ -10,7 +10,7 @@ #if !defined(AFX_RESOURCE_DLL) || defined(AFX_TARG_ENU) LANGUAGE LANG_ENGLISH, SUBLANG_ENGLISH_US -#define FileDescription "IIS AspNetCore Module V2. Commit: " CommitHash +#define FileDescription "IIS ASP.NET Core Module V2. Commit: " CommitHash ///////////////////////////////////////////////////////////////////////////// // diff --git a/src/AspNetCoreModuleV2/CommonLib/EventLog.cpp b/src/AspNetCoreModuleV2/CommonLib/EventLog.cpp index 24992232de..fe97805a39 100644 --- a/src/AspNetCoreModuleV2/CommonLib/EventLog.cpp +++ b/src/AspNetCoreModuleV2/CommonLib/EventLog.cpp @@ -1,8 +1,10 @@ // Copyright (c) .NET Foundation. All rights reserved. // Licensed under the MIT License. See License.txt in the project root for license information. +#include #include "EventLog.h" #include "debugutil.h" +#include "StringHelpers.h" extern HANDLE g_hEventLog; @@ -13,6 +15,19 @@ EventLog::LogEvent( _In_ LPCWSTR pstrMsg ) { + // Static locals to avoid getting the process ID and string multiple times. + // Effectively have the same semantics as global variables, except initialized + // on first occurence. + static const auto processIdString = GetProcessIdString(); + static const auto versionInfoString = GetVersionInfoString(); + + std::array eventLogDataStrings + { + pstrMsg, + processIdString.c_str(), + versionInfoString.c_str() + }; + if (g_hEventLog != NULL) { ReportEventW(g_hEventLog, @@ -20,9 +35,9 @@ EventLog::LogEvent( 0, // wCategory dwEventId, NULL, // lpUserSid - 1, // wNumStrings + 3, // wNumStrings 0, // dwDataSize, - &pstrMsg, + eventLogDataStrings.data(), NULL // lpRawData ); } diff --git a/src/AspNetCoreModuleV2/CommonLib/debugutil.cpp b/src/AspNetCoreModuleV2/CommonLib/debugutil.cpp index 45e1d7ceab..3988d78796 100644 --- a/src/AspNetCoreModuleV2/CommonLib/debugutil.cpp +++ b/src/AspNetCoreModuleV2/CommonLib/debugutil.cpp @@ -13,6 +13,7 @@ #include "exceptions.h" #include "atlbase.h" #include "config_utility.h" +#include "StringHelpers.h" inline HANDLE g_logFile = INVALID_HANDLE_VALUE; inline HMODULE g_hModule; @@ -21,43 +22,72 @@ inline SRWLOCK g_logFileLock; HRESULT PrintDebugHeader() { - DWORD verHandle = 0; - UINT size = 0; - LPVOID lpBuffer = NULL; + // Major, minor are stored in dwFileVersionMS field and patch, build in dwFileVersionLS field as pair of 32 bit numbers + DebugPrintf(ASPNETCORE_DEBUG_FLAG_INFO, "Initializing logs for %S. %S. %S.", + GetModuleName().c_str(), + GetProcessIdString().c_str(), + GetVersionInfoString().c_str() + ); - WCHAR path[MAX_PATH]; - RETURN_LAST_ERROR_IF(!GetModuleFileName(g_hModule, path, sizeof(path))); + return S_OK; +} - DWORD verSize = GetFileVersionInfoSize(path, &verHandle); - RETURN_LAST_ERROR_IF(verSize == 0); +std::wstring +GetProcessIdString() +{ + return format(L"Process Id: %u.", GetCurrentProcessId()); +} - // Allocate memory to hold data structure returned by GetFileVersionInfo - std::vector verData(verSize); - - RETURN_LAST_ERROR_IF(!GetFileVersionInfo(path, verHandle, verSize, verData.data())); - RETURN_LAST_ERROR_IF(!VerQueryValue(verData.data(), L"\\", &lpBuffer, &size)); - - auto verInfo = reinterpret_cast(lpBuffer); - // Check result signature - if (verInfo->dwSignature == VS_FFI_SIGNATURE) +std::wstring +GetVersionInfoString() +{ + auto func = [](std::wstring& res) { + DWORD verHandle = 0; + UINT size = 0; + LPVOID lpBuffer = NULL; + + auto path = GetModuleName(); + + DWORD verSize = GetFileVersionInfoSize(path.c_str(), &verHandle); + RETURN_LAST_ERROR_IF(verSize == 0); + + // Allocate memory to hold data structure returned by GetFileVersionInfo + std::vector verData(verSize); + + RETURN_LAST_ERROR_IF(!GetFileVersionInfo(path.c_str(), verHandle, verSize, verData.data())); + RETURN_LAST_ERROR_IF(!VerQueryValue(verData.data(), L"\\", &lpBuffer, &size)); + + auto verInfo = reinterpret_cast(lpBuffer); + if (verInfo->dwSignature != VS_FFI_SIGNATURE) + { + RETURN_IF_FAILED(E_FAIL); + } + LPVOID pvProductName = NULL; unsigned int iProductNameLen = 0; RETURN_LAST_ERROR_IF(!VerQueryValue(verData.data(), _T("\\StringFileInfo\\040904b0\\FileDescription"), &pvProductName, &iProductNameLen)); - // Major, minor are stored in dwFileVersionMS field and patch, build in dwFileVersionLS field as pair of 32 bit numbers - DebugPrintf(ASPNETCORE_DEBUG_FLAG_INFO, "Initializing logs for %S. ProcessId: %d. File Version: %d.%d.%d.%d. Description: %S", - path, - GetCurrentProcessId(), - ( verInfo->dwFileVersionMS >> 16 ) & 0xffff, - ( verInfo->dwFileVersionMS >> 0 ) & 0xffff, - ( verInfo->dwFileVersionLS >> 16 ) & 0xffff, - ( verInfo->dwFileVersionLS >> 0 ) & 0xffff, - pvProductName - ); - } + res = format(L"File Version: %d.%d.%d.%d. Description: %s", + (verInfo->dwFileVersionMS >> 16) & 0xffff, + (verInfo->dwFileVersionMS >> 0) & 0xffff, + (verInfo->dwFileVersionLS >> 16) & 0xffff, + (verInfo->dwFileVersionLS >> 0) & 0xffff, + pvProductName); + return S_OK; + }; - return S_OK; + std::wstring versionInfoString; + + return func(versionInfoString) == S_OK ? versionInfoString : L""; +} + +std::wstring +GetModuleName() +{ + WCHAR path[MAX_PATH]; + LOG_LAST_ERROR_IF(GetModuleFileName(g_hModule, path, sizeof(path))); + return path; } void SetDebugFlags(const std::wstring &debugValue) diff --git a/src/AspNetCoreModuleV2/CommonLib/debugutil.h b/src/AspNetCoreModuleV2/CommonLib/debugutil.h index b070794d0a..611d00d53d 100644 --- a/src/AspNetCoreModuleV2/CommonLib/debugutil.h +++ b/src/AspNetCoreModuleV2/CommonLib/debugutil.h @@ -49,3 +49,12 @@ DebugPrintf( LPCSTR szFormat, ... ); + +std::wstring +GetProcessIdString(); + +std::wstring +GetVersionInfoString(); + +std::wstring +GetModuleName(); diff --git a/src/AspNetCoreModuleV2/InProcessRequestHandler/inprocessrequesthandler.rc b/src/AspNetCoreModuleV2/InProcessRequestHandler/inprocessrequesthandler.rc index bf1e4d5191..2cddc56709 100644 --- a/src/AspNetCoreModuleV2/InProcessRequestHandler/inprocessrequesthandler.rc +++ b/src/AspNetCoreModuleV2/InProcessRequestHandler/inprocessrequesthandler.rc @@ -9,7 +9,7 @@ #if !defined(AFX_RESOURCE_DLL) || defined(AFX_TARG_ENU) LANGUAGE LANG_ENGLISH, SUBLANG_ENGLISH_US -#define FileDescription "IIS ASP.NET Core Module Request Handler. Commit: " CommitHash +#define FileDescription "IIS ASP.NET Core Module V2 Request Handler. Commit: " CommitHash ///////////////////////////////////////////////////////////////////////////// // diff --git a/src/AspNetCoreModuleV2/OutOfProcessRequestHandler/outofprocessrequesthandler.rc b/src/AspNetCoreModuleV2/OutOfProcessRequestHandler/outofprocessrequesthandler.rc index eb32a08eb7..654496a8c5 100644 --- a/src/AspNetCoreModuleV2/OutOfProcessRequestHandler/outofprocessrequesthandler.rc +++ b/src/AspNetCoreModuleV2/OutOfProcessRequestHandler/outofprocessrequesthandler.rc @@ -9,7 +9,7 @@ #if !defined(AFX_RESOURCE_DLL) || defined(AFX_TARG_ENU) LANGUAGE LANG_ENGLISH, SUBLANG_ENGLISH_US -#define FileDescription "IIS ASP.NET Core Module Request Handler. Commit: " CommitHash +#define FileDescription "IIS ASP.NET Core Module V2 Request Handler. Commit: " CommitHash ///////////////////////////////////////////////////////////////////////////// // diff --git a/test/Common.FunctionalTests/Inprocess/EventLogTests.cs b/test/Common.FunctionalTests/Inprocess/EventLogTests.cs index 77abc90190..296d99f789 100644 --- a/test/Common.FunctionalTests/Inprocess/EventLogTests.cs +++ b/test/Common.FunctionalTests/Inprocess/EventLogTests.cs @@ -1,7 +1,6 @@ // Copyright (c) .NET Foundation. All rights reserved. // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. -using System.Net; using System.Threading.Tasks; using Microsoft.AspNetCore.Server.IIS.FunctionalTests.Utilities; using Microsoft.AspNetCore.Testing.xunit; diff --git a/test/Common.FunctionalTests/Inprocess/LoggingTests.cs b/test/Common.FunctionalTests/Inprocess/LoggingTests.cs index 7ef360a487..e530befc51 100644 --- a/test/Common.FunctionalTests/Inprocess/LoggingTests.cs +++ b/test/Common.FunctionalTests/Inprocess/LoggingTests.cs @@ -200,8 +200,8 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests var logContents = streamReader.ReadToEnd(); Assert.Contains("[aspnetcorev2.dll]", logContents); Assert.Contains("[aspnetcorev2_inprocess.dll]", logContents); - Assert.Contains("Description: IIS AspNetCore Module V2. Commit:", logContents); - Assert.Contains("Description: IIS ASP.NET Core Module Request Handler. Commit:", logContents); + Assert.Contains("Description: IIS ASP.NET Core Module V2. Commit:", logContents); + Assert.Contains("Description: IIS ASP.NET Core Module V2 Request Handler. Commit:", logContents); } } } diff --git a/test/Common.FunctionalTests/Utilities/EventLogHelpers.cs b/test/Common.FunctionalTests/Utilities/EventLogHelpers.cs index c4ca40436a..c85a78bdd3 100644 --- a/test/Common.FunctionalTests/Utilities/EventLogHelpers.cs +++ b/test/Common.FunctionalTests/Utilities/EventLogHelpers.cs @@ -1,17 +1,24 @@ // Copyright (c) .NET Foundation. All rights reserved. // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. +using System; +using System.Collections.Generic; +using System.Diagnostics; +using System.Linq; using System.Text; using System.Text.RegularExpressions; +using Microsoft.AspNetCore.Server.IntegrationTesting; using Microsoft.AspNetCore.Server.IntegrationTesting.IIS; using Microsoft.Extensions.Logging.Testing; using Xunit; +using Xunit.Sdk; namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests { public class EventLogHelpers { private static readonly Regex EventLogRegex = new Regex("Event Log: (?.+?)End Event Log Message.", RegexOptions.Singleline | RegexOptions.Compiled); + public static void VerifyEventLogEvent(IISDeploymentResult deploymentResult, ITestSink testSink, string expectedRegexMatchString) { Assert.True(deploymentResult.HostProcess.HasExited); @@ -36,6 +43,43 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests Assert.True(count > 0, $"'{expectedRegexMatchString}' didn't match any event log messaged"); Assert.True(count < 2, $"'{expectedRegexMatchString}' matched more then one event log message"); + + var eventLog = new EventLog("Application"); + + // Perf: only get the last 20 events from the event log. + // Eventlog is already sorted based on time of event in ascending time. + // Add results in reverse order. + var expectedRegexEventLog = new Regex(expectedRegexMatchString); + var processIdString = $"Process Id: {deploymentResult.HostProcess.Id}."; + + for (var i = eventLog.Entries.Count - 1; i >= eventLog.Entries.Count - 20; i--) + { + var eventLogEntry = eventLog.Entries[i]; + if (eventLogEntry.ReplacementStrings == null || + eventLogEntry.ReplacementStrings.Length < 3) + { + continue; + } + + // ReplacementStings == EventData collection in EventLog + // This is unaffected if event providers are not registered correctly + if (eventLogEntry.Source == AncmVersionToMatch(deploymentResult) && + processIdString == eventLogEntry.ReplacementStrings[1] && + expectedRegex.IsMatch(eventLogEntry.ReplacementStrings[0])) + { + return; + } + } + + Assert.True(false, $"'{expectedRegexMatchString}' didn't match any event log messaged."); + } + + private static string AncmVersionToMatch(IISDeploymentResult deploymentResult) + { + return "IIS " + + (deploymentResult.DeploymentParameters.ServerType == ServerType.IISExpress ? "Express " : "") + + "AspNetCore Module" + + (deploymentResult.DeploymentParameters.AncmVersion == AncmVersion.AspNetCoreModuleV2 ? " V2" : ""); } } }