Skip to content

Commit 2cbf5bd

Browse files
jkotalikjkotalik
authored
Query event logs when verifying event log messages. (#1323)
1 parent 9d5cbe1 commit 2cbf5bd

File tree

10 files changed

+133
-36
lines changed

10 files changed

+133
-36
lines changed

‎src/AspNetCoreModuleV1/AspNetCore/aspnetcoremodule.rc

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -10,7 +10,7 @@
1010
#if !defined(AFX_RESOURCE_DLL) || defined(AFX_TARG_ENU)
1111
LANGUAGE LANG_ENGLISH, SUBLANG_ENGLISH_US
1212

13-
#define FileDescription "IIS AspNetCore Module. Commit: " CommitHash
13+
#define FileDescription "IIS ASP.NET Core Module. Commit: " CommitHash
1414

1515
/////////////////////////////////////////////////////////////////////////////
1616
//

‎src/AspNetCoreModuleV2/AspNetCore/aspnetcoremodule.rc

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -10,7 +10,7 @@
1010
#if !defined(AFX_RESOURCE_DLL) || defined(AFX_TARG_ENU)
1111
LANGUAGE LANG_ENGLISH, SUBLANG_ENGLISH_US
1212

13-
#define FileDescription "IIS AspNetCore Module V2. Commit: " CommitHash
13+
#define FileDescription "IIS ASP.NET Core Module V2. Commit: " CommitHash
1414

1515
/////////////////////////////////////////////////////////////////////////////
1616
//

‎src/AspNetCoreModuleV2/CommonLib/EventLog.cpp

Lines changed: 17 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,8 +1,10 @@
11
// Copyright (c) .NET Foundation. All rights reserved.
22
// Licensed under the MIT License. See License.txt in the project root for license information.
33

4+
#include <array>
45
#include "EventLog.h"
56
#include "debugutil.h"
7+
#include "StringHelpers.h"
68

79
extern HANDLE g_hEventLog;
810

@@ -13,16 +15,29 @@ EventLog::LogEvent(
1315
_In_ LPCWSTR pstrMsg
1416
)
1517
{
18+
// Static locals to avoid getting the process ID and string multiple times.
19+
// Effectively have the same semantics as global variables, except initialized
20+
// on first occurence.
21+
static const auto processIdString = GetProcessIdString();
22+
static const auto versionInfoString = GetVersionInfoString();
23+
24+
std::array<LPCWSTR, 3> eventLogDataStrings
25+
{
26+
pstrMsg,
27+
processIdString.c_str(),
28+
versionInfoString.c_str()
29+
};
30+
1631
if (g_hEventLog != NULL)
1732
{
1833
ReportEventW(g_hEventLog,
1934
dwEventInfoType,
2035
0, // wCategory
2136
dwEventId,
2237
NULL, // lpUserSid
23-
1, // wNumStrings
38+
3, // wNumStrings
2439
0, // dwDataSize,
25-
&pstrMsg,
40+
eventLogDataStrings.data(),
2641
NULL // lpRawData
2742
);
2843
}

‎src/AspNetCoreModuleV2/CommonLib/debugutil.cpp

Lines changed: 57 additions & 27 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@
1313
#include "exceptions.h"
1414
#include "atlbase.h"
1515
#include "config_utility.h"
16+
#include "StringHelpers.h"
1617

1718
inline HANDLE g_logFile = INVALID_HANDLE_VALUE;
1819
inline HMODULE g_hModule;
@@ -21,43 +22,72 @@ inline SRWLOCK g_logFileLock;
2122
HRESULT
2223
PrintDebugHeader()
2324
{
24-
DWORD verHandle = 0;
25-
UINT size = 0;
26-
LPVOID lpBuffer = NULL;
25+
// Major, minor are stored in dwFileVersionMS field and patch, build in dwFileVersionLS field as pair of 32 bit numbers
26+
DebugPrintf(ASPNETCORE_DEBUG_FLAG_INFO, "Initializing logs for %S. %S. %S.",
27+
GetModuleName().c_str(),
28+
GetProcessIdString().c_str(),
29+
GetVersionInfoString().c_str()
30+
);
2731

28-
WCHAR path[MAX_PATH];
29-
RETURN_LAST_ERROR_IF(!GetModuleFileName(g_hModule, path, sizeof(path)));
32+
return S_OK;
33+
}
3034

31-
DWORD verSize = GetFileVersionInfoSize(path, &verHandle);
32-
RETURN_LAST_ERROR_IF(verSize == 0);
35+
std::wstring
36+
GetProcessIdString()
37+
{
38+
return format(L"Process Id: %u.", GetCurrentProcessId());
39+
}
3340

34-
// Allocate memory to hold data structure returned by GetFileVersionInfo
35-
std::vector<BYTE> verData(verSize);
41+
std::wstring
42+
GetVersionInfoString()
43+
{
44+
auto func = [](std::wstring& res)
45+
{
46+
DWORD verHandle = 0;
47+
UINT size = 0;
48+
LPVOID lpBuffer = NULL;
3649

37-
RETURN_LAST_ERROR_IF(!GetFileVersionInfo(path, verHandle, verSize, verData.data()));
38-
RETURN_LAST_ERROR_IF(!VerQueryValue(verData.data(), L"\\", &lpBuffer, &size));
50+
auto path = GetModuleName();
51+
52+
DWORD verSize = GetFileVersionInfoSize(path.c_str(), &verHandle);
53+
RETURN_LAST_ERROR_IF(verSize == 0);
54+
55+
// Allocate memory to hold data structure returned by GetFileVersionInfo
56+
std::vector<BYTE> verData(verSize);
57+
58+
RETURN_LAST_ERROR_IF(!GetFileVersionInfo(path.c_str(), verHandle, verSize, verData.data()));
59+
RETURN_LAST_ERROR_IF(!VerQueryValue(verData.data(), L"\\", &lpBuffer, &size));
60+
61+
auto verInfo = reinterpret_cast<VS_FIXEDFILEINFO *>(lpBuffer);
62+
if (verInfo->dwSignature != VS_FFI_SIGNATURE)
63+
{
64+
RETURN_IF_FAILED(E_FAIL);
65+
}
3966

40-
auto verInfo = reinterpret_cast<VS_FIXEDFILEINFO *>(lpBuffer);
41-
// Check result signature
42-
if (verInfo->dwSignature == VS_FFI_SIGNATURE)
43-
{
4467
LPVOID pvProductName = NULL;
4568
unsigned int iProductNameLen = 0;
4669
RETURN_LAST_ERROR_IF(!VerQueryValue(verData.data(), _T("\\StringFileInfo\\040904b0\\FileDescription"), &pvProductName, &iProductNameLen));
4770

48-
// Major, minor are stored in dwFileVersionMS field and patch, build in dwFileVersionLS field as pair of 32 bit numbers
49-
DebugPrintf(ASPNETCORE_DEBUG_FLAG_INFO, "Initializing logs for %S. ProcessId: %d. File Version: %d.%d.%d.%d. Description: %S",
50-
path,
51-
GetCurrentProcessId(),
52-
( verInfo->dwFileVersionMS >> 16 ) & 0xffff,
53-
( verInfo->dwFileVersionMS >> 0 ) & 0xffff,
54-
( verInfo->dwFileVersionLS >> 16 ) & 0xffff,
55-
( verInfo->dwFileVersionLS >> 0 ) & 0xffff,
56-
pvProductName
57-
);
58-
}
71+
res = format(L"File Version: %d.%d.%d.%d. Description: %s",
72+
(verInfo->dwFileVersionMS >> 16) & 0xffff,
73+
(verInfo->dwFileVersionMS >> 0) & 0xffff,
74+
(verInfo->dwFileVersionLS >> 16) & 0xffff,
75+
(verInfo->dwFileVersionLS >> 0) & 0xffff,
76+
pvProductName);
77+
return S_OK;
78+
};
5979

60-
return S_OK;
80+
std::wstring versionInfoString;
81+
82+
return func(versionInfoString) == S_OK ? versionInfoString : L"";
83+
}
84+
85+
std::wstring
86+
GetModuleName()
87+
{
88+
WCHAR path[MAX_PATH];
89+
LOG_LAST_ERROR_IF(GetModuleFileName(g_hModule, path, sizeof(path)));
90+
return path;
6191
}
6292

6393
void SetDebugFlags(const std::wstring &debugValue)

‎src/AspNetCoreModuleV2/CommonLib/debugutil.h

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -49,3 +49,12 @@ DebugPrintf(
4949
LPCSTR szFormat,
5050
...
5151
);
52+
53+
std::wstring
54+
GetProcessIdString();
55+
56+
std::wstring
57+
GetVersionInfoString();
58+
59+
std::wstring
60+
GetModuleName();

‎src/AspNetCoreModuleV2/InProcessRequestHandler/inprocessrequesthandler.rc

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -9,7 +9,7 @@
99
#if !defined(AFX_RESOURCE_DLL) || defined(AFX_TARG_ENU)
1010
LANGUAGE LANG_ENGLISH, SUBLANG_ENGLISH_US
1111

12-
#define FileDescription "IIS ASP.NET Core Module Request Handler. Commit: " CommitHash
12+
#define FileDescription "IIS ASP.NET Core Module V2 Request Handler. Commit: " CommitHash
1313

1414
/////////////////////////////////////////////////////////////////////////////
1515
//

‎src/AspNetCoreModuleV2/OutOfProcessRequestHandler/outofprocessrequesthandler.rc

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -9,7 +9,7 @@
99
#if !defined(AFX_RESOURCE_DLL) || defined(AFX_TARG_ENU)
1010
LANGUAGE LANG_ENGLISH, SUBLANG_ENGLISH_US
1111

12-
#define FileDescription "IIS ASP.NET Core Module Request Handler. Commit: " CommitHash
12+
#define FileDescription "IIS ASP.NET Core Module V2 Request Handler. Commit: " CommitHash
1313

1414
/////////////////////////////////////////////////////////////////////////////
1515
//

‎test/Common.FunctionalTests/Inprocess/EventLogTests.cs

Lines changed: 0 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,6 @@
11
// Copyright (c) .NET Foundation. All rights reserved.
22
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
33

4-
using System.Net;
54
using System.Threading.Tasks;
65
using Microsoft.AspNetCore.Server.IIS.FunctionalTests.Utilities;
76
using Microsoft.AspNetCore.Testing.xunit;

‎test/Common.FunctionalTests/Inprocess/LoggingTests.cs

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -200,8 +200,8 @@ private static void AssertLogs(string logPath)
200200
var logContents = streamReader.ReadToEnd();
201201
Assert.Contains("[aspnetcorev2.dll]", logContents);
202202
Assert.Contains("[aspnetcorev2_inprocess.dll]", logContents);
203-
Assert.Contains("Description: IIS AspNetCore Module V2. Commit:", logContents);
204-
Assert.Contains("Description: IIS ASP.NET Core Module Request Handler. Commit:", logContents);
203+
Assert.Contains("Description: IIS ASP.NET Core Module V2. Commit:", logContents);
204+
Assert.Contains("Description: IIS ASP.NET Core Module V2 Request Handler. Commit:", logContents);
205205
}
206206
}
207207
}

‎test/Common.FunctionalTests/Utilities/EventLogHelpers.cs

Lines changed: 44 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,17 +1,24 @@
11
// Copyright (c) .NET Foundation. All rights reserved.
22
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
33

4+
using System;
5+
using System.Collections.Generic;
6+
using System.Diagnostics;
7+
using System.Linq;
48
using System.Text;
59
using System.Text.RegularExpressions;
10+
using Microsoft.AspNetCore.Server.IntegrationTesting;
611
using Microsoft.AspNetCore.Server.IntegrationTesting.IIS;
712
using Microsoft.Extensions.Logging.Testing;
813
using Xunit;
14+
using Xunit.Sdk;
915

1016
namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
1117
{
1218
public class EventLogHelpers
1319
{
1420
private static readonly Regex EventLogRegex = new Regex("Event Log: (?<EventLogMessage>.+?)End Event Log Message.", RegexOptions.Singleline | RegexOptions.Compiled);
21+
1522
public static void VerifyEventLogEvent(IISDeploymentResult deploymentResult, ITestSink testSink, string expectedRegexMatchString)
1623
{
1724
Assert.True(deploymentResult.HostProcess.HasExited);
@@ -36,6 +43,43 @@ public static void VerifyEventLogEvent(IISDeploymentResult deploymentResult, ITe
3643

3744
Assert.True(count > 0, $"'{expectedRegexMatchString}' didn't match any event log messaged");
3845
Assert.True(count < 2, $"'{expectedRegexMatchString}' matched more then one event log message");
46+
47+
var eventLog = new EventLog("Application");
48+
49+
// Perf: only get the last 20 events from the event log.
50+
// Eventlog is already sorted based on time of event in ascending time.
51+
// Add results in reverse order.
52+
var expectedRegexEventLog = new Regex(expectedRegexMatchString);
53+
var processIdString = $"Process Id: {deploymentResult.HostProcess.Id}.";
54+
55+
for (var i = eventLog.Entries.Count - 1; i >= eventLog.Entries.Count - 20; i--)
56+
{
57+
var eventLogEntry = eventLog.Entries[i];
58+
if (eventLogEntry.ReplacementStrings == null ||
59+
eventLogEntry.ReplacementStrings.Length < 3)
60+
{
61+
continue;
62+
}
63+
64+
// ReplacementStings == EventData collection in EventLog
65+
// This is unaffected if event providers are not registered correctly
66+
if (eventLogEntry.Source == AncmVersionToMatch(deploymentResult) &&
67+
processIdString == eventLogEntry.ReplacementStrings[1] &&
68+
expectedRegex.IsMatch(eventLogEntry.ReplacementStrings[0]))
69+
{
70+
return;
71+
}
72+
}
73+
74+
Assert.True(false, $"'{expectedRegexMatchString}' didn't match any event log messaged.");
75+
}
76+
77+
private static string AncmVersionToMatch(IISDeploymentResult deploymentResult)
78+
{
79+
return "IIS " +
80+
(deploymentResult.DeploymentParameters.ServerType == ServerType.IISExpress ? "Express " : "") +
81+
"AspNetCore Module" +
82+
(deploymentResult.DeploymentParameters.AncmVersion == AncmVersion.AspNetCoreModuleV2 ? " V2" : "");
3983
}
4084
}
4185
}

0 commit comments

Comments
 (0)