Skip to content

Commit e14cb11

Browse files
authored
Refactor the NGEN tracking fix to be more performant (#6598)
## Summary of changes This PR refactor the NGEN tracking fix to remove the `lock` and the `unordered_set` and reuse the `module_ids` lock and a vector + 3 mdMethodDef field. ## Reason for change After #6588 was merged, @andrewlock saw some performance impact in the Execution Benchmarks. ## Implementation details Remove a lock and an unordered_set for just a field comparison + a vector Contains if a field is found. This should improve everything on the missed hit because is just a comparison over 3 fields. ## Test coverage ## Other details <!-- Fixes #{issue} --> <!-- ⚠️ Note: where possible, please obtain 2 approvals prior to merging. Unless CODEOWNERS specifies otherwise, for external teams it is typically best to have one review from a team member, and one review from apm-dotnet. Trivial changes do not require 2 reviews. -->
1 parent a1dee56 commit e14cb11

File tree

3 files changed

+90
-104
lines changed

3 files changed

+90
-104
lines changed

tracer/src/Datadog.Tracer.Native/clr_helpers.h

-22
Original file line numberDiff line numberDiff line change
@@ -628,28 +628,6 @@ struct GenericTypeProps
628628
HRESULT TryParse();
629629
};
630630

631-
struct ModuleIDMethodDef {
632-
ModuleID ModuleId;
633-
mdMethodDef MethodDef;
634-
635-
// Hash function
636-
std::size_t operator()(const ModuleIDMethodDef& i) const {
637-
return static_cast<std::size_t>(i.ModuleId) ^ (static_cast<std::size_t>(i.MethodDef) << 1);
638-
}
639-
// Comparison for equality
640-
bool operator ()(const ModuleIDMethodDef& lhs, const ModuleIDMethodDef& rhs) const {
641-
return lhs.ModuleId == rhs.ModuleId && lhs.MethodDef == rhs.MethodDef;
642-
}
643-
644-
bool operator ==(const ModuleIDMethodDef& other) const {
645-
return this->ModuleId == other.ModuleId && this->MethodDef == other.MethodDef;
646-
}
647-
648-
bool operator !=(const ModuleIDMethodDef& other) const {
649-
return this->ModuleId != other.ModuleId || this->MethodDef != other.MethodDef;
650-
}
651-
};
652-
653631
RuntimeInformation GetRuntimeInformation(ICorProfilerInfo4* info);
654632

655633
AssemblyInfo GetAssemblyInfo(ICorProfilerInfo4* info, const AssemblyID& assembly_id);

tracer/src/Datadog.Tracer.Native/cor_profiler.cpp

+83-75
Original file line numberDiff line numberDiff line change
@@ -343,6 +343,7 @@ HRESULT STDMETHODCALLTYPE CorProfiler::Initialize(IUnknown* cor_profiler_info_un
343343

344344
//
345345
managed_profiler_assembly_reference = AssemblyReference::GetFromCache(managed_profiler_full_assembly_version);
346+
managedInternalModules_.reserve(10);
346347

347348
const auto currentModuleFileName = shared::GetCurrentModuleFileName();
348349
if (currentModuleFileName == shared::EmptyWStr)
@@ -504,8 +505,7 @@ HRESULT STDMETHODCALLTYPE CorProfiler::AssemblyLoadFinished(AssemblyID assembly_
504505
return S_OK;
505506
}
506507

507-
void CorProfiler::RewritingPInvokeMaps(const ModuleID module_id,
508-
const ModuleMetadata& module_metadata,
508+
void CorProfiler::RewritingPInvokeMaps(const ModuleMetadata& module_metadata,
509509
const shared::WSTRING& rewrite_reason,
510510
const shared::WSTRING& nativemethods_type_name,
511511
const shared::WSTRING& library_path)
@@ -570,10 +570,6 @@ void CorProfiler::RewritingPInvokeMaps(const ModuleID module_id,
570570
shared::WSTRING(importName).c_str(),
571571
profiler_ref);
572572

573-
// Store this methodDef token in the internal tokens list
574-
auto intTokens = internal_rewrite_tokens.Get();
575-
intTokens->insert({ module_id, methodDef });
576-
577573
if (FAILED(hr))
578574
{
579575
Logger::Warn("ModuleLoadFinished: DefinePinvokeMap to the actual profiler file path "
@@ -799,6 +795,7 @@ HRESULT CorProfiler::TryRejitModule(ModuleID module_id, std::vector<ModuleID>& m
799795
module_info.assembly.name == system_private_corelib_assemblyName))
800796
{
801797
corlib_module_loaded = true;
798+
corlib_module_id = module_id;
802799
corlib_app_domain_id = app_domain_id;
803800

804801
ComPtr<IUnknown> metadata_interfaces;
@@ -909,9 +906,6 @@ HRESULT CorProfiler::TryRejitModule(ModuleID module_id, std::vector<ModuleID>& m
909906
}
910907
}
911908

912-
// Add the module_id to the module metadata vector (to allow NGEN analysis later)
913-
modules.push_back(module_id);
914-
915909
if (module_info.assembly.name == managed_profiler_name)
916910
{
917911
// Fix PInvoke Rewriting
@@ -940,17 +934,17 @@ HRESULT CorProfiler::TryRejitModule(ModuleID module_id, std::vector<ModuleID>& m
940934
const auto& assemblyVersion = assemblyImport.version.str();
941935

942936
Logger::Info("ModuleLoadFinished: ", managed_profiler_name, " v", assemblyVersion, " - Fix PInvoke maps");
943-
managedProfilerModuleId_ = module_id;
937+
managedInternalModules_.push_back(module_id);
944938
#ifdef _WIN32
945-
RewritingPInvokeMaps(module_id, module_metadata, WStr("windows"), windows_nativemethods_type);
946-
RewritingPInvokeMaps(module_id, module_metadata, WStr("ASM"), appsec_windows_nativemethods_type);
947-
RewritingPInvokeMaps(module_id, module_metadata, WStr("debugger"), debugger_windows_nativemethods_type);
948-
RewritingPInvokeMaps(module_id, module_metadata, WStr("fault_tolerant"), fault_tolerant_windows_nativemethods_type);
939+
RewritingPInvokeMaps(module_metadata, WStr("windows"), windows_nativemethods_type);
940+
RewritingPInvokeMaps(module_metadata, WStr("ASM"), appsec_windows_nativemethods_type);
941+
RewritingPInvokeMaps(module_metadata, WStr("debugger"), debugger_windows_nativemethods_type);
942+
RewritingPInvokeMaps(module_metadata, WStr("fault_tolerant"), fault_tolerant_windows_nativemethods_type);
949943
#else
950-
RewritingPInvokeMaps(module_id, module_metadata, WStr("non-windows"), nonwindows_nativemethods_type);
951-
RewritingPInvokeMaps(module_id, module_metadata, WStr("ASM"), appsec_nonwindows_nativemethods_type);
952-
RewritingPInvokeMaps(module_id, module_metadata, WStr("debugger"), debugger_nonwindows_nativemethods_type);
953-
RewritingPInvokeMaps(module_id, module_metadata, WStr("fault_tolerant"), fault_tolerant_nonwindows_nativemethods_type);
944+
RewritingPInvokeMaps(module_metadata, WStr("non-windows"), nonwindows_nativemethods_type);
945+
RewritingPInvokeMaps(module_metadata, WStr("ASM"), appsec_nonwindows_nativemethods_type);
946+
RewritingPInvokeMaps(module_metadata, WStr("debugger"), debugger_nonwindows_nativemethods_type);
947+
RewritingPInvokeMaps(module_metadata, WStr("fault_tolerant"), fault_tolerant_nonwindows_nativemethods_type);
954948
#endif // _WIN32
955949

956950
mdTypeDef bubbleUpTypeDef;
@@ -964,15 +958,15 @@ HRESULT CorProfiler::TryRejitModule(ModuleID module_id, std::vector<ModuleID>& m
964958
if (fs::exists(native_loader_library_path))
965959
{
966960
auto native_loader_file_path = shared::ToWSTRING(native_loader_library_path);
967-
RewritingPInvokeMaps(module_id, module_metadata, WStr("native loader"), native_loader_nativemethods_type, native_loader_file_path);
961+
RewritingPInvokeMaps(module_metadata, WStr("native loader"), native_loader_nativemethods_type, native_loader_file_path);
968962
}
969963

970964
if (ShouldRewriteProfilerMaps())
971965
{
972966
auto profiler_library_path = shared::GetEnvironmentValue(WStr("DD_INTERNAL_PROFILING_NATIVE_ENGINE_PATH"));
973967
if (!profiler_library_path.empty() && fs::exists(profiler_library_path))
974968
{
975-
RewritingPInvokeMaps(module_id, module_metadata, WStr("continuous profiler"), profiler_nativemethods_type, profiler_library_path);
969+
RewritingPInvokeMaps(module_metadata, WStr("continuous profiler"), profiler_nativemethods_type, profiler_library_path);
976970
}
977971
}
978972

@@ -1042,11 +1036,14 @@ HRESULT CorProfiler::TryRejitModule(ModuleID module_id, std::vector<ModuleID>& m
10421036
const auto& assemblyVersion = assemblyImport.version.str();
10431037

10441038
Logger::Info("ModuleLoadFinished: ", manual_instrumentation_name, " v", assemblyVersion, " - RewriteIsManualInstrumentationOnly");
1039+
managedInternalModules_.push_back(module_id);
10451040

10461041
// Rewrite Instrumentation.IsManualInstrumentationOnly()
10471042
RewriteIsManualInstrumentationOnly(module_metadata, module_id);
10481043
}
10491044

1045+
modules.push_back(module_id);
1046+
10501047
bool searchForTraceAttribute = trace_annotations_enabled;
10511048
if (searchForTraceAttribute)
10521049
{
@@ -1761,7 +1758,6 @@ HRESULT STDMETHODCALLTYPE CorProfiler::AppDomainShutdownFinished(AppDomainID app
17611758
const auto& count = first_jit_compilation_app_domains.erase(appDomainId);
17621759

17631760
Logger::Debug("AppDomainShutdownFinished: AppDomain: ", appDomainId, ", removed ", count, " elements");
1764-
17651761
return S_OK;
17661762
}
17671763

@@ -2721,10 +2717,8 @@ HRESULT CorProfiler::RewriteForDistributedTracing(const ModuleMetadata& module_m
27212717
module_metadata.metadata_import));
27222718
}
27232719

2724-
// Store this methodDef token in the internal tokens list
2725-
auto intTokens = internal_rewrite_tokens.Get();
2726-
intTokens->insert({ module_id, getDistributedTraceMethodDef });
2727-
2720+
Logger::Debug("MethodDef was added as an internal rewrite: ", getDistributedTraceMethodDef);
2721+
getDistributedTraceMethodDef_ = getDistributedTraceMethodDef;
27282722
return hr;
27292723
}
27302724

@@ -2799,8 +2793,7 @@ HRESULT CorProfiler::RewriteForTelemetry(const ModuleMetadata& module_metadata,
27992793

28002794
// Store this methodDef token in the internal tokens list
28012795
Logger::Debug("MethodDef was added as an internal rewrite: ", getNativeTracerVersionMethodDef);
2802-
auto intTokens = internal_rewrite_tokens.Get();
2803-
intTokens->insert({ module_id, getNativeTracerVersionMethodDef });
2796+
getNativeTracerVersionMethodDef_ = getNativeTracerVersionMethodDef;
28042797

28052798
return hr;
28062799
}
@@ -2866,8 +2859,7 @@ HRESULT CorProfiler::RewriteIsManualInstrumentationOnly(const ModuleMetadata& mo
28662859

28672860
// Store this methodDef token in the internal tokens list
28682861
Logger::Debug("MethodDef was added as an internal rewrite: ", isAutoEnabledMethodDef);
2869-
auto intTokens = internal_rewrite_tokens.Get();
2870-
intTokens->insert({ module_id, isAutoEnabledMethodDef });
2862+
isManualInstrumentationOnlyMethodDef_ = isAutoEnabledMethodDef;
28712863

28722864
return hr;
28732865
}
@@ -3256,10 +3248,6 @@ HRESULT CorProfiler::RunILStartupHook(const ComPtr<IMetaDataEmit2>& metadata_emi
32563248
return hr;
32573249
}
32583250

3259-
// Store this methodDef token in the internal tokens list
3260-
auto intTokens = internal_rewrite_tokens.Get();
3261-
intTokens->insert({ module_id, function_token });
3262-
32633251
return S_OK;
32643252
}
32653253

@@ -4364,11 +4352,31 @@ HRESULT STDMETHODCALLTYPE CorProfiler::JITCachedFunctionSearchStarted(FunctionID
43644352
}
43654353

43664354
auto _ = trace::Stats::Instance()->JITCachedFunctionSearchStartedMeasure();
4367-
if (!pbUseCachedFunction)
4355+
if (pbUseCachedFunction == nullptr || !*pbUseCachedFunction)
43684356
{
43694357
return S_OK;
43704358
}
43714359

4360+
// Extract Module metadata
4361+
ModuleID module_id;
4362+
mdToken function_token = mdTokenNil;
4363+
4364+
HRESULT hr = this->info_->GetFunctionInfo(functionId, nullptr, &module_id, &function_token);
4365+
if (FAILED(hr))
4366+
{
4367+
Logger::Warn("JITCachedFunctionSearchStarted: Call to ICorProfilerInfo.GetFunctionInfo() failed for ",
4368+
functionId);
4369+
return S_OK;
4370+
}
4371+
4372+
// Verify if is the COR module
4373+
if (module_id == corlib_module_id)
4374+
{
4375+
// we don't rewrite the COR module, so we accept all the images from there.
4376+
*pbUseCachedFunction = true;
4377+
return S_OK;
4378+
}
4379+
43724380
// keep this lock until we are done using the module,
43734381
// to prevent it from unloading while in use
43744382
auto modulesOpt = module_ids.TryGet();
@@ -4382,18 +4390,6 @@ HRESULT STDMETHODCALLTYPE CorProfiler::JITCachedFunctionSearchStarted(FunctionID
43824390

43834391
auto& modules = modulesOpt.value();
43844392

4385-
// Extract Module metadata
4386-
ModuleID module_id;
4387-
mdToken function_token = mdTokenNil;
4388-
4389-
HRESULT hr = this->info_->GetFunctionInfo(functionId, nullptr, &module_id, &function_token);
4390-
if (FAILED(hr))
4391-
{
4392-
Logger::Warn("JITCachedFunctionSearchStarted: Call to ICorProfilerInfo4.GetFunctionInfo() failed for ",
4393-
functionId);
4394-
return S_OK;
4395-
}
4396-
43974393
// Call RequestRejitOrRevert for register inliners and current NGEN module.
43984394
if (rejit_handler != nullptr)
43994395
{
@@ -4410,30 +4406,50 @@ HRESULT STDMETHODCALLTYPE CorProfiler::JITCachedFunctionSearchStarted(FunctionID
44104406
return S_OK;
44114407
}
44124408

4409+
bool isAnInternalModule = false;
4410+
44134411
// Verify that we have the metadata for this module
44144412
if (!shared::Contains(modules.Ref(), module_id))
44154413
{
4416-
// we haven't stored a ModuleMetadata for this module,
4417-
// so there's nothing to do here, we accept the NGEN image.
4418-
*pbUseCachedFunction = true;
4419-
return S_OK;
4414+
isAnInternalModule = shared::Contains(managedInternalModules_, module_id);
4415+
if (!isAnInternalModule)
4416+
{
4417+
// we haven't stored a ModuleMetadata for this module,
4418+
// so there's nothing to do here, we accept the NGEN image.
4419+
*pbUseCachedFunction = true;
4420+
return S_OK;
4421+
}
44204422
}
44214423

4422-
const auto& module_info = GetModuleInfo(this->info_, module_id);
4423-
if (!module_info.IsValid())
4424+
// let's get the AssemblyID
4425+
DWORD module_path_len = 0;
4426+
AssemblyID assembly_id = 0;
4427+
hr = this->info_->GetModuleInfo(module_id, nullptr, 0, &module_path_len,
4428+
nullptr, &assembly_id);
4429+
if (FAILED(hr) || module_path_len == 0)
44244430
{
4425-
Logger::Debug("Disabling NGEN. ModuleInfo is not valid. ModuleId=", module_id);
4431+
Logger::Warn("JITCachedFunctionSearchStarted: Call to ICorProfilerInfo.GetModuleInfo() failed for ",
4432+
functionId);
44264433
return S_OK;
44274434
}
44284435

4429-
const auto& appDomainId = module_info.assembly.app_domain_id;
4436+
// now the assembly info
4437+
DWORD assembly_name_len = 0;
4438+
AppDomainID app_domain_id;
4439+
hr = this->info_->GetAssemblyInfo(assembly_id, 0, &assembly_name_len, nullptr, &app_domain_id, nullptr);
4440+
if (FAILED(hr) || assembly_name_len == 0)
4441+
{
4442+
Logger::Warn("JITCachedFunctionSearchStarted: Call to ICorProfilerInfo.GetAssemblyInfo() failed for ",
4443+
functionId);
4444+
return S_OK;
4445+
}
44304446

44314447
const bool has_loader_injected_in_appdomain =
4432-
first_jit_compilation_app_domains.find(appDomainId) != first_jit_compilation_app_domains.end();
4448+
first_jit_compilation_app_domains.find(app_domain_id) != first_jit_compilation_app_domains.end();
44334449

44344450
if (!has_loader_injected_in_appdomain)
44354451
{
4436-
Logger::Debug("Disabling NGEN due to missing loader.");
4452+
Logger::Debug("JITCachedFunctionSearchStarted: Disabling NGEN due to missing loader.");
44374453
// The loader is missing in this AppDomain, we skip the NGEN image to allow the JITCompilationStart inject
44384454
// it.
44394455
*pbUseCachedFunction = false;
@@ -4442,37 +4458,32 @@ HRESULT STDMETHODCALLTYPE CorProfiler::JITCachedFunctionSearchStarted(FunctionID
44424458

44434459
// Let's check if the method has been rewritten internally
44444460
// if that's the case we don't accept the image
4445-
auto internalTokensOpt = internal_rewrite_tokens.TryGet();
4446-
if (!internalTokensOpt.has_value())
4447-
{
4448-
Logger::Error(
4449-
"JITCachedFunctionSearchStarted: Failed on exception while tried to acquire the lock for the internal_rewrite_tokens collection for functionId ",
4450-
functionId);
4451-
return S_OK;
4452-
}
4453-
4454-
auto& internalTokens = internalTokensOpt.value();
4455-
bool hasBeenRewritten = internalTokens->find({ module_id, function_token }) != internalTokens->end();
4461+
bool isKnownMethodDef =
4462+
function_token == getDistributedTraceMethodDef_ ||
4463+
function_token == getNativeTracerVersionMethodDef_ ||
4464+
function_token == isManualInstrumentationOnlyMethodDef_;
4465+
bool hasBeenRewritten = isKnownMethodDef && isAnInternalModule;
44564466
if (hasBeenRewritten)
44574467
{
44584468
// If we are in debug mode and the image is rejected because has been rewritten then let's write a couple of logs
44594469
if (Logger::IsDebugEnabled())
44604470
{
4471+
const auto& module_info = GetModuleInfo(this->info_, module_id);
44614472
ComPtr<IUnknown> metadata_interfaces;
44624473
if (this->info_->GetModuleMetaData(module_id, ofRead, IID_IMetaDataImport2,
44634474
metadata_interfaces.GetAddressOf()) == S_OK)
44644475
{
44654476
const auto& metadata_import = metadata_interfaces.As<IMetaDataImport2>(IID_IMetaDataImport);
44664477
auto functionInfo = GetFunctionInfo(metadata_import, function_token);
44674478

4468-
Logger::Debug("NGEN Image: Rejected (because rewritten) for Module: ", module_info.assembly.name,
4479+
Logger::Debug("JITCachedFunctionSearchStarted: Rejected (because rewritten) for Module: ", module_info.assembly.name,
44694480
", Method:", functionInfo.type.name, ".", functionInfo.name,
44704481
"() previous value = ", *pbUseCachedFunction ? "true" : "false", "[moduleId=", module_id,
44714482
", methodDef=", HexStr(function_token), "]");
44724483
}
44734484
else
44744485
{
4475-
Logger::Debug("NGEN Image: Rejected (because rewritten) for Module: ", module_info.assembly.name,
4486+
Logger::Debug("JITCachedFunctionSearchStarted: Rejected (because rewritten) for Module: ", module_info.assembly.name,
44764487
", Function: ", HexStr(function_token),
44774488
" previous value = ", *pbUseCachedFunction ? "true" : "false");
44784489
}
@@ -4482,10 +4493,6 @@ HRESULT STDMETHODCALLTYPE CorProfiler::JITCachedFunctionSearchStarted(FunctionID
44824493
*pbUseCachedFunction = false;
44834494
return S_OK;
44844495
}
4485-
else
4486-
{
4487-
Logger::Debug("JITCachedFunctionSearchStarted: non rejected by internal token on token: ", function_token, " Looking into a hashset with ", internalTokens->size(), " elements");
4488-
}
44894496

44904497
// JITCachedFunctionSearchStarted has a different behaviour between .NET Framework and .NET Core
44914498
// On .NET Framework when we reject bcl images the rejit calls of the integrations for those bcl assemblies
@@ -4504,21 +4511,22 @@ HRESULT STDMETHODCALLTYPE CorProfiler::JITCachedFunctionSearchStarted(FunctionID
45044511
// If we are in debug mode and the image is rejected because has been rejitted then let's write a couple of logs
45054512
if (Logger::IsDebugEnabled() && hasBeenRejitted)
45064513
{
4514+
const auto& module_info = GetModuleInfo(this->info_, module_id);
45074515
ComPtr<IUnknown> metadata_interfaces;
45084516
if (this->info_->GetModuleMetaData(module_id, ofRead, IID_IMetaDataImport2,
45094517
metadata_interfaces.GetAddressOf()) == S_OK)
45104518
{
45114519
const auto& metadata_import = metadata_interfaces.As<IMetaDataImport2>(IID_IMetaDataImport);
45124520
auto functionInfo = GetFunctionInfo(metadata_import, function_token);
45134521

4514-
Logger::Debug("NGEN Image: Rejected (because rejitted) for Module: ", module_info.assembly.name,
4522+
Logger::Debug("JITCachedFunctionSearchStarted: Rejected (because rejitted) for Module: ", module_info.assembly.name,
45154523
", Method:", functionInfo.type.name, ".", functionInfo.name,
45164524
"() previous value = ", *pbUseCachedFunction ? "true" : "false", "[moduleId=", module_id,
45174525
", methodDef=", HexStr(function_token), "]");
45184526
}
45194527
else
45204528
{
4521-
Logger::Debug("NGEN Image: Rejected (because rejitted) for Module: ", module_info.assembly.name,
4529+
Logger::Debug("JITCachedFunctionSearchStarted: Rejected (because rejitted) for Module: ", module_info.assembly.name,
45224530
", Function: ", HexStr(function_token),
45234531
" previous value = ", *pbUseCachedFunction ? "true" : "false");
45244532
}

0 commit comments

Comments
 (0)