Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Log error if missing bytecode instrumentation method #1520

5 changes: 5 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -23,6 +23,11 @@ This component adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.h
- Get rid of unnecessary service restarts during the IIS unregistration,
in the PowerShell script module.

### Added

- Error message on the native log if bytecode instrumentation type is missing all
instrumentation methods [#1499](https://github.com/open-telemetry/opentelemetry-dotnet-instrumentation/issues/1499).

## [0.4.0-beta.1](https://github.com/open-telemetry/opentelemetry-dotnet-instrumentation/releases/tag/v0.4.0-beta.1)

### Added
Expand Down
39 changes: 36 additions & 3 deletions src/OpenTelemetry.AutoInstrumentation.Native/cor_profiler.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -2494,14 +2494,47 @@ HRESULT CorProfiler::CallTarget_RewriterCallback(RejitHandlerModule* moduleHandl
&wrapper_type_def);
if (FAILED(hr) || wrapper_type_def == mdTypeDefNil)
{
Logger::Warn("*** CallTarget_RewriterCallback() Failed for: ", caller->type.name, ".", caller->name,
Logger::Error("*** CallTarget_RewriterCallback() Failed for: ", caller->type.name, ".", caller->name,
Copy link
Member

@pellared pellared Nov 2, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Should it not be a warning? It is an oddity, but the application and instrumentation would continue to work without any bad side-effects. Should the user react when he notices such an error?

Maybe we should even "accept" such behavior so that we could use e.g. #if NETFRAMEWORK on a whole instrumentation class? Then we could even change this level to debug.

Leaving it for a discussion + potentially separate PR.

"() integration type not found on the managed profiler module HRESULT=", HResultStr(hr),
" IntegrationType=", wrapper.type_name);
return S_FALSE;
}

// TODO: Use the method signature to validate also the method, tracking via
// https://github.com/open-telemetry/opentelemetry-dotnet-instrumentation/issue/1499
// CallTarget instrumentation doesn't inject calls to the instrumentation methods via IL rewrite.
// It injects the OpenTelemetry.AutoInstrumentation.CallTarget.CallTargetInvoker, written in managed code,
// that uses reflection to find the expected instrumentation methods on the instrumentation wrapper type.
// If the wrapper type doesn't have any of the expected instrumentation methods "nothing happens", but,
// the JIT code of the targeted method is modified anyway. To avoid injecting instrumentation that does
// nothing and give a clear error message the code below ensures that at least one of the expected methods is
// implemented on the wrapper type.
static const LPCWSTR expected_wrapper_methods[] = { WStr("OnMethodBegin"), WStr("OnMethodEnd"), WStr("OnAsyncMethodEnd") };
bool found_wrapper_method = false;
for (LPCWSTR expected_wrapper_method : expected_wrapper_methods)
{
mdMethodDef wrapper_method_def[1];
HCORENUM phEnum = NULL;
ULONG cTokens,
hr = instrumentation_module_metadata->metadata_import->EnumMethodsWithName(
&phEnum,
wrapper_type_def,
expected_wrapper_method,
wrapper_method_def,
1,
&cTokens);
if (hr == S_OK && cTokens > 0)
{
found_wrapper_method = true;
break;
}
}

if (!found_wrapper_method)
{
Logger::Error("*** CallTarget_RewriterCallback() Failed for: ", caller->type.name, ".", caller->name,
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Some comment as above.

"() integration type found but none of the wrapper methods expected by CallTargetInvoker was found ",
"IntegrationType=", wrapper.type_name);
return S_FALSE;
}
}

ModuleID module_id = moduleHandler->GetModuleId();
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -129,7 +129,7 @@ HRESULT MetadataBuilder::StoreWrapperMethodRef(const MethodReplacement& method_r

// If the signature data size is greater than zero means we need to load the methodRef
// for CallSite instrumentation.
// In case of the signature data size is zero we asume we are in a calltarget scenario
// In case of the signature data size is zero we assume we are in a CallTarget scenario
// where we use the TypeRef but not a MemberRef.

if (signature_data.size() > 0)
Expand Down
4 changes: 4 additions & 0 deletions test/IntegrationTests/StrongNamedTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -42,6 +42,10 @@ public async Task SubmitsTraces()
SetEnvironmentVariable("OTEL_DOTNET_AUTO_INTEGRATIONS_FILE", integrationsFile);
RunTestApplication(otlpTraceCollectorPort: collector.Port);

// TODO: When native logs are moved to an EventSource implementation check for the log
// TODO: entries reporting the missing instrumentation type and missing instrumentation methods.
// TODO: See https://github.com/open-telemetry/opentelemetry-dotnet-instrumentation/issues/960

collector.AssertExpectations();
}
}
22 changes: 22 additions & 0 deletions test/IntegrationTests/StrongNamedTestsIntegrations.json
Original file line number Diff line number Diff line change
Expand Up @@ -46,6 +46,28 @@
"type": "OpenTelemetry.AutoInstrumentation.Instrumentations.Validations.MissingInstrumentationType",
"action": "CallTargetModification"
}
},
{
"caller": {},
"target": {
pjanotti marked this conversation as resolved.
Show resolved Hide resolved
"assembly": "TestLibrary.InstrumentationTarget",
"type": "TestLibrary.InstrumentationTarget.Command",
"method": "InstrumentationTargetMissingBytecodeInstrumentationMethod",
"signature_types": [
"System.Void"
],
"minimum_major": 1,
"minimum_minor": 0,
"minimum_patch": 0,
"maximum_major": 1,
"maximum_minor": 65535,
"maximum_patch": 65535
},
"wrapper": {
"assembly": "OpenTelemetry.AutoInstrumentation",
"type": "OpenTelemetry.AutoInstrumentation.DuckTyping.DuckAttribute",
"action": "CallTargetModification"
}
}
]
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -25,5 +25,6 @@ public static void Main(string[] args)
var command = new Command();
command.Execute();
command.InstrumentationTargetMissingBytecodeInstrumentationType();
command.InstrumentationTargetMissingBytecodeInstrumentationMethod();
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -29,4 +29,9 @@ public void InstrumentationTargetMissingBytecodeInstrumentationType()
{
Thread.Sleep(0); // Just to have some call to outside code.
}

public void InstrumentationTargetMissingBytecodeInstrumentationMethod()
{
Thread.Yield(); // Just to have some call to outside code.
}
}
47 changes: 46 additions & 1 deletion tools/IntegrationsJsonGenerator/Program.cs
Original file line number Diff line number Diff line change
Expand Up @@ -65,7 +65,7 @@
var productionIntegrations = integrations.Where(x => x.Key != "StrongNamedValidation").Select(x => x.Value)
.OrderBy(x => x.Name).ToArray();

var testIntegrations = integrations.Where(x => x.Key == "StrongNamedValidation").Select(x => x.Value)
var testIntegrations = integrations.Where(x => x.Key == "StrongNamedValidation").Select(x => AppendMockIntegrations(x.Value))
.OrderBy(x => x.Name).ToArray();

UpdateIntegrationFile(Path.Combine(solutionFolder, "integrations.json"), productionIntegrations);
Expand Down Expand Up @@ -164,3 +164,48 @@ void UpdateIntegrationFile(string filePath, Integration[] productionIntegrations

static string GetSourceFilePathName([CallerFilePath] string callerFilePath = null)
=> callerFilePath ?? string.Empty;

static Integration AppendMockIntegrations(Integration testIntegration)
{
// Add some special cases used by the integration tests. This way the integrations
// file used in the integrations test doesn't change on each run of the tool.
var targetAssembly = testIntegration.MethodReplacements[0].Target.Assembly;
var targetType = testIntegration.MethodReplacements[0].Target.Type;
var targetSignatureTypes = testIntegration.MethodReplacements[0].Target.SignatureTypes;

testIntegration.MethodReplacements.Add(new MethodReplacement
{
Target = new Target
{
Assembly = testIntegration.MethodReplacements[0].Target.Assembly,
Type = targetType,
Method = "InstrumentationTargetMissingBytecodeInstrumentationType",
SignatureTypes = targetSignatureTypes,
MaximumMajor = 1,
MinimumMajor = 1,
},
Wrapper = new Wrapper
{
Type = "OpenTelemetry.AutoInstrumentation.Instrumentations.Validations.MissingInstrumentationType",
},
});

testIntegration.MethodReplacements.Add(new MethodReplacement
{
Target = new Target
{
Assembly = testIntegration.MethodReplacements[0].Target.Assembly,
Type = targetType,
Method = "InstrumentationTargetMissingBytecodeInstrumentationMethod",
SignatureTypes = targetSignatureTypes,
MaximumMajor = 1,
MinimumMajor = 1,
},
Wrapper = new Wrapper
{
Type = "OpenTelemetry.AutoInstrumentation.DuckTyping.DuckAttribute",
},
});

return testIntegration;
}