Skip to content

Commit 0756bde

Browse files
thenextmanawakecoding
thenextman
authored and
awakecoding
committed
feat: basic profiling support
1 parent 0c295a5 commit 0756bde

File tree

9 files changed

+246
-47
lines changed

9 files changed

+246
-47
lines changed

‎CMakeLists.txt‎

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -27,9 +27,11 @@ set(MSRDPEX_VERSION "${MSRDPEX_VERSION_MAJOR}.${MSRDPEX_VERSION_MINOR}.${MSRDPEX
2727

2828
message(STATUS "VERSION: ${MSRDPEX_VERSION}")
2929

30+
string(TIMESTAMP CURRENT_YEAR "%Y")
31+
3032
set(MSRDPEX_NAME "MsRdpEx")
3133
set(MSRDPEX_VENDOR "Devolutions Inc.")
32-
set(MSRDPEX_COPYRIGHT "Copyright 2021-2023 ${MSRDPEX_VENDOR}")
34+
set(MSRDPEX_COPYRIGHT "Copyright 2021-${CURRENT_YEAR} ${MSRDPEX_VENDOR}")
3335

3436
set(CMAKE_ARCHIVE_OUTPUT_DIRECTORY ${CMAKE_BINARY_DIR})
3537
set(CMAKE_LIBRARY_OUTPUT_DIRECTORY ${CMAKE_BINARY_DIR})

‎dll/ApiHooks.cpp‎

Lines changed: 15 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@
88
#include <MsRdpEx/NameResolver.h>
99
#include <MsRdpEx/RdpInstance.h>
1010
#include <MsRdpEx/Environment.h>
11+
#include <MsRdpEx/Stopwatch.h>
1112

1213
#include <MsRdpEx/OutputMirror.h>
1314

@@ -113,7 +114,6 @@ Func_LoadLibraryExW Real_LoadLibraryExW = NULL;
113114
HMODULE WINAPI Hook_LoadLibraryExA(LPCSTR lpLibFileName, HANDLE hFile, DWORD dwFlags)
114115
{
115116
HMODULE hModule = NULL;
116-
const char* filename = MsRdpEx_FileBase(lpLibFileName);
117117

118118
// LoadLibraryExA calls LoadLibraryExW under the hood, don't log here
119119
//MsRdpEx_LogPrint(DEBUG, "LoadLibraryExA: %s", lpLibFileName);
@@ -435,7 +435,8 @@ bool WINAPI MsRdpEx_CaptureBlt(
435435

436436
instance->GetOutputMirrorObject((LPVOID*) &outputMirror);
437437

438-
if (!outputMirror) {
438+
if (!outputMirror)
439+
{
439440
outputMirror = MsRdpEx_OutputMirror_New();
440441
MsRdpEx_OutputMirror_SetDumpBitmapUpdates(outputMirror, dumpBitmapUpdates);
441442
MsRdpEx_OutputMirror_SetVideoRecordingEnabled(outputMirror, videoRecordingEnabled);
@@ -456,7 +457,6 @@ bool WINAPI MsRdpEx_CaptureBlt(
456457
HDC hShadowDC = MsRdpEx_OutputMirror_GetShadowDC(outputMirror);
457458
BitBlt(hShadowDC, dstX, dstY, width, height, hdcSrc, srcX, srcY, SRCCOPY);
458459
MsRdpEx_OutputMirror_Unlock(outputMirror);
459-
460460
MsRdpEx_OutputMirror_DumpFrame(outputMirror);
461461

462462
captured = true;
@@ -469,13 +469,16 @@ BOOL WINAPI Hook_BitBlt(
469469
HDC hdcSrc, int srcX, int srcY, DWORD rop)
470470
{
471471
BOOL status;
472+
MsRdpEx_Stopwatch stopwatch;
472473

473474
status = Real_BitBlt(hdcDst, dstX, dstY, width, height, hdcSrc, srcX, srcY, rop);
474475

476+
MsRdpEx_Stopwatch_Init(&stopwatch, MSRDPEX_PROF_TRACE, true);
475477
bool captured = MsRdpEx_CaptureBlt(hdcDst, dstX, dstY, width, height, hdcSrc, srcX, srcY);
476-
477-
if (captured) {
478-
MsRdpEx_LogPrint(TRACE, "BitBlt: %d,%d %dx%d %d,%d", dstX, dstY, width, height, srcX, srcY);
478+
479+
if (captured)
480+
{
481+
MsRdpEx_LogPrint(TRACE, "BitBlt: %d,%d %dx%d %d,%d [%.3fms]", dstX, dstY, width, height, srcX, srcY, MsRdpEx_Stopwatch_GetTime(&stopwatch));
479482
}
480483

481484
return status;
@@ -491,13 +494,16 @@ BOOL WINAPI Hook_StretchBlt(
491494
HDC hdcSrc, int srcX, int srcY, int srcW, int srcH, DWORD rop)
492495
{
493496
BOOL status;
497+
MsRdpEx_Stopwatch stopwatch;
494498

495499
status = Real_StretchBlt(hdcDst, dstX, dstY, dstW, dstH, hdcSrc, srcX, srcY, srcW, srcH, rop);
496500

501+
MsRdpEx_Stopwatch_Init(&stopwatch, MSRDPEX_PROF_TRACE, true);
497502
bool captured = MsRdpEx_CaptureBlt(hdcDst, srcX, srcY, srcW, srcH, hdcSrc, srcX, srcY);
498503

499-
if (captured) {
500-
MsRdpEx_LogPrint(TRACE, "StretchBlt: %d,%d %dx%d %d,%d %dx%d", dstX, dstY, dstW, dstH, srcX, srcY, srcW, srcH);
504+
if (captured)
505+
{
506+
MsRdpEx_LogPrint(TRACE, "StretchBlt: %d,%d %dx%d %d,%d %dx%d [%.3fms])", dstX, dstY, dstW, dstH, srcX, srcY, srcW, srcH, MsRdpEx_Stopwatch_GetTime(&stopwatch));
501507
}
502508

503509
end:
@@ -697,7 +703,7 @@ LRESULT CALLBACK Hook_IHWndProc(HWND hWnd, UINT uMsg, WPARAM wParam, LPARAM lPar
697703
IMsRdpExInstance* instance = NULL;
698704
CMsRdpExtendedSettings* pExtendedSettings = NULL;
699705

700-
MsRdpEx_LogPrint(DEBUG, "IHWndProc: %s (%d)", MsRdpEx_GetWindowMessageName(uMsg), uMsg);
706+
//MsRdpEx_LogPrint(DEBUG, "IHWndProc: %s (%d)", MsRdpEx_GetWindowMessageName(uMsg), uMsg);
701707

702708
if (uMsg == WM_NCCREATE)
703709
{

‎dll/CMakeLists.txt‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,7 @@ source_group("Resources" FILES ${MSRDPEX_RESOURCES})
1616

1717
set(MSRDPEX_HEADERS
1818
"${MSRDPEX_INCLUDE_DIR}/Sspi.h"
19+
"${MSRDPEX_INCLUDE_DIR}/Stopwatch.h"
1920
"${MSRDPEX_INCLUDE_DIR}/Stream.h"
2021
"${MSRDPEX_INCLUDE_DIR}/Detours.h"
2122
"${MSRDPEX_INCLUDE_DIR}/Memory.h"
@@ -40,6 +41,7 @@ set(MSRDPEX_SOURCES
4041
KeyMaps.cpp
4142
Environment.c
4243
NameResolver.c
44+
Stopwatch.c
4345
DpiHelper.cpp
4446
DpiHelper.h
4547
Sspi.cpp
@@ -104,6 +106,8 @@ set(MSRDPEX_LIBS
104106
advapi32.lib
105107
comctl32.lib)
106108

109+
target_compile_options(MsRdpEx_Dll PRIVATE /W4)
110+
107111
target_link_libraries(MsRdpEx_Dll ${MSRDPEX_LIBS})
108112

109113
set_target_properties(MsRdpEx_Dll PROPERTIES OUTPUT_NAME "MsRdpEx")

‎dll/Log.c‎

Lines changed: 52 additions & 32 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,8 @@ static uint32_t g_LogLevel = MSRDPEX_LOG_DEBUG;
1313

1414
#define MSRDPEX_LOG_MAX_LINE 8192
1515

16+
LPCSTR LOG_LEVELS[7] = { "TRACE", "DEBUG", "INFO", "WARN", "ERROR", "FATAL", "OFF" };
17+
1618
bool MsRdpEx_IsLogLevelActive(uint32_t logLevel)
1719
{
1820
if (!g_LogEnabled)
@@ -24,29 +26,37 @@ bool MsRdpEx_IsLogLevelActive(uint32_t logLevel)
2426
return logLevel >= g_LogLevel;
2527
}
2628

27-
bool MsRdpEx_LogVA(const char* format, va_list args)
29+
bool MsRdpEx_LogVA(uint32_t level, const char* format, va_list args)
2830
{
2931
if (!g_LogFile)
3032
return true;
3133

34+
SYSTEMTIME st;
35+
GetLocalTime(&st);
36+
37+
DWORD pid = GetCurrentProcessId();
38+
DWORD tid = GetCurrentThreadId();
39+
3240
char message[MSRDPEX_LOG_MAX_LINE];
3341
vsnprintf_s(message, MSRDPEX_LOG_MAX_LINE - 1, _TRUNCATE, format, args);
34-
strcat_s(message, MSRDPEX_LOG_MAX_LINE - 1, "\n");
3542

36-
if (g_LogFile) {
37-
fprintf(g_LogFile, message);
38-
fflush(g_LogFile); // WARNING: performance drag
39-
}
43+
fprintf(g_LogFile, "[%s] %04d-%02d-%02d %02d:%02d:%02d.%03d PID:%lu TID:%lu - %s\n",
44+
LOG_LEVELS[level],
45+
st.wYear, st.wMonth, st.wDay,
46+
st.wHour, st.wMinute, st.wSecond, st.wMilliseconds,
47+
pid, tid,
48+
message);
49+
fflush(g_LogFile); // WARNING: performance drag
4050

4151
return true;
4252
}
4353

44-
bool MsRdpEx_Log(const char* format, ...)
54+
bool MsRdpEx_Log(uint32_t level, const char* format, ...)
4555
{
4656
bool status;
4757
va_list args;
4858
va_start(args, format);
49-
status = MsRdpEx_LogVA(format, args);
59+
status = MsRdpEx_LogVA(level, format, args);
5060
va_end(args);
5161
return status;
5262
}
@@ -119,32 +129,42 @@ void MsRdpEx_LogEnvInit()
119129
envvar = MsRdpEx_GetEnv("MSRDPEX_LOG_LEVEL");
120130

121131
if (envvar) {
122-
int ival = atoi(envvar);
123132

124-
if ((ival >= 0) && (ival <= 6)) {
125-
MsRdpEx_SetLogLevel((uint32_t) ival);
133+
if (MsRdpEx_StringIEquals(envvar, "TRACE"))
134+
{
135+
MsRdpEx_SetLogLevel(MSRDPEX_LOG_TRACE);
126136
}
127-
else {
128-
if (MsRdpEx_StringIEquals(envvar, "TRACE")) {
129-
MsRdpEx_SetLogLevel(MSRDPEX_LOG_TRACE);
130-
}
131-
else if (MsRdpEx_StringIEquals(envvar, "DEBUG")) {
132-
MsRdpEx_SetLogLevel(MSRDPEX_LOG_DEBUG);
133-
}
134-
else if (MsRdpEx_StringIEquals(envvar, "INFO")) {
135-
MsRdpEx_SetLogLevel(MSRDPEX_LOG_INFO);
136-
}
137-
else if (MsRdpEx_StringIEquals(envvar, "WARN")) {
138-
MsRdpEx_SetLogLevel(MSRDPEX_LOG_WARN);
139-
}
140-
else if (MsRdpEx_StringIEquals(envvar, "ERROR")) {
141-
MsRdpEx_SetLogLevel(MSRDPEX_LOG_ERROR);
142-
}
143-
else if (MsRdpEx_StringIEquals(envvar, "FATAL")) {
144-
MsRdpEx_SetLogLevel(MSRDPEX_LOG_FATAL);
145-
}
146-
else if (MsRdpEx_StringIEquals(envvar, "OFF")) {
147-
MsRdpEx_SetLogLevel(MSRDPEX_LOG_OFF);
137+
else if (MsRdpEx_StringIEquals(envvar, "DEBUG"))
138+
{
139+
MsRdpEx_SetLogLevel(MSRDPEX_LOG_DEBUG);
140+
}
141+
else if (MsRdpEx_StringIEquals(envvar, "INFO"))
142+
{
143+
MsRdpEx_SetLogLevel(MSRDPEX_LOG_INFO);
144+
}
145+
else if (MsRdpEx_StringIEquals(envvar, "WARN"))
146+
{
147+
MsRdpEx_SetLogLevel(MSRDPEX_LOG_WARN);
148+
}
149+
else if (MsRdpEx_StringIEquals(envvar, "ERROR"))
150+
{
151+
MsRdpEx_SetLogLevel(MSRDPEX_LOG_ERROR);
152+
}
153+
else if (MsRdpEx_StringIEquals(envvar, "FATAL"))
154+
{
155+
MsRdpEx_SetLogLevel(MSRDPEX_LOG_FATAL);
156+
}
157+
else if (MsRdpEx_StringIEquals(envvar, "OFF"))
158+
{
159+
MsRdpEx_SetLogLevel(MSRDPEX_LOG_OFF);
160+
}
161+
else
162+
{
163+
int ival = atoi(envvar);
164+
165+
if ((ival >= 0) && (ival <= 6))
166+
{
167+
MsRdpEx_SetLogLevel((uint32_t)ival);
148168
}
149169
}
150170
}

‎dll/MsRdpEx.cpp‎

Lines changed: 2 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -2,11 +2,9 @@
22
#include "MsRdpEx.h"
33

44
#include <MsRdpEx/MsRdpEx.h>
5-
65
#include <MsRdpEx/Environment.h>
7-
6+
#include <MsRdpEx/Stopwatch.h>
87
#include <MsRdpEx/RdpInstance.h>
9-
108
#include <MsRdpEx/Detours.h>
119

1210
#include "RdpDvcClient.h"
@@ -798,6 +796,7 @@ void MsRdpEx_Load()
798796
MsRdpEx_InitPaths(MSRDPEX_ALL_PATHS);
799797

800798
MsRdpEx_LogOpen();
799+
MsRdpEx_ProfilingInit();
801800

802801
if (g_IsClientProcess) {
803802
if (g_IsOOBClient) {

‎dll/OutputMirror.c‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@
22
#include "MsRdpEx.h"
33

44
#include <MsRdpEx/Environment.h>
5+
#include <MsRdpEx/Stopwatch.h>
56
#include <MsRdpEx/VideoRecorder.h>
67
#include <MsRdpEx/OutputMirror.h>
78

@@ -31,7 +32,12 @@ struct _MsRdpEx_OutputMirror
3132

3233
void MsRdpEx_OutputMirror_Lock(MsRdpEx_OutputMirror* ctx)
3334
{
35+
MsRdpEx_Stopwatch stopwatch;
36+
MsRdpEx_Stopwatch_Init(&stopwatch, MSRDPEX_PROF_TRACE, true);
37+
3438
EnterCriticalSection(&ctx->lock);
39+
40+
MsRdpEx_Stopwatch_Print(&stopwatch, MSRDPEX_LOG_TRACE, "MsRdpEx_OutputMirror_Lock");
3541
}
3642

3743
void MsRdpEx_OutputMirror_Unlock(MsRdpEx_OutputMirror* ctx)

0 commit comments

Comments
 (0)