diff --git a/shared/src/Datadog.Trace.ClrProfiler.Native/cor_profiler.cpp b/shared/src/Datadog.Trace.ClrProfiler.Native/cor_profiler.cpp index 29314b8d97fd..32c96bc46102 100644 --- a/shared/src/Datadog.Trace.ClrProfiler.Native/cor_profiler.cpp +++ b/shared/src/Datadog.Trace.ClrProfiler.Native/cor_profiler.cpp @@ -153,6 +153,83 @@ namespace datadog::shared::nativeloader return CORPROF_E_PROFILER_CANCEL_ACTIVATION; } } + + // If we weren't on the explicit include list, then try to filter out `dotnet build` etc. + // We don't want to instrument _build_ processes in dotnet by default, as they generally + // don't give useful information, add latency, and risk triggering bugs in the runtime, + // particularly around shutdown, like this one: https://github.com/dotnet/runtime/issues/55441 + const auto [process_command_line , tokenized_command_line] = GetCurrentProcessCommandLine(); + Log::Info("Process CommandLine: ", process_command_line); + + if (!process_command_line.empty()) + { + const auto isDotNetProcess = process_name == WStr("dotnet") || process_name == WStr("dotnet.exe"); + const auto token_count = tokenized_command_line.size(); + if (isDotNetProcess && token_count > 1) + { + // Exclude: + // - dotnet build, dotnet build myproject.csproj etc + // - dotnet build-server + // - (... dotnet COMMAND commands listed below) + // - dotnet tool ... + // - dotnet new ... + // + // There are other commands we're choosing not to check because they + // wouldn't normally be called on a build or production server, just locally + // - dotnet add package, dotnet add reference + // - dotnet sln + // - dotnet workload + // - etc + // + // There are some commands that we explicitly DO want to instrument + // i.e. dotnet run + // i.e. dotnet test + // i.e. dotnet vstest + // i.e. dotnet exec (except specific commands) + bool is_ignored_command = false; + const auto token1 = tokenized_command_line[1]; + if(token1 == WStr("exec")) + { + // compiler is invoked with arguments something like this: + // dotnet exec /usr/share/dotnet/sdk/6.0.400/Roslyn/bincore/csc.dll /noconfig @/tmp/tmp8895f601306443a6a54388ecc6dcfc44.rsp + // so we check the arguments to see if any of them are an invocation of one of the dlls we want to ignore. + // We don't just check the second argument because the command could set additional flags + // for the exec function + for (int i = 2; i < token_count; ++i) + { + const auto current_token = tokenized_command_line[i]; + if(!current_token.empty() && + (EndsWith(current_token, WStr("csc.dll")) + || EndsWith(current_token, WStr("VBCSCompiler.dll")))) + { + is_ignored_command = true; + break; + } + } + } + else if(!token1.empty()) + { + is_ignored_command = + token1 == WStr("build") || + token1 == WStr("build-server") || + token1 == WStr("clean") || + token1 == WStr("msbuild") || + token1 == WStr("new") || + token1 == WStr("nuget") || + token1 == WStr("pack") || + token1 == WStr("publish") || + token1 == WStr("restore") || + token1 == WStr("tool"); + } + + if (is_ignored_command) + { + Log::Info("The Tracer Profiler has been disabled because the process is 'dotnet' " + "but an unsupported command was detected"); + return CORPROF_E_PROFILER_CANCEL_ACTIVATION; + } + } + } } // diff --git a/shared/src/native-src/pal.h b/shared/src/native-src/pal.h index 180eb70103a6..2030ed1279be 100644 --- a/shared/src/native-src/pal.h +++ b/shared/src/native-src/pal.h @@ -4,6 +4,7 @@ #include "windows.h" #include +#include #else @@ -129,20 +130,33 @@ inline WSTRING GetCurrentProcessName() #endif } -inline WSTRING GetCurrentProcessCommandLine() +inline std::tuple> GetCurrentProcessCommandLine() { + std::vector args; #ifdef _WIN32 - return WSTRING(GetCommandLine()); + const auto cmdLine = GetCommandLine(); + int argCount; + const auto arguments = CommandLineToArgvW(cmdLine, &argCount); + + for (int i = 0; i < argCount; i++) + { + args.push_back(Trim(arguments[i])); + } + + return { cmdLine, args }; #elif MACOS std::string name; int argCount = *_NSGetArgc(); char** arguments = *_NSGetArgv(); + for (int i = 0; i < argCount; i++) { - char* currentArg = arguments[i]; - name = name + " " + std::string(currentArg); + const auto currentArg = std::string(arguments[i]); + args.push_back(Trim(ToWSTRING(currentArg))); + name = name + " " + currentArg; } - return Trim(ToWSTRING(name)); + + return { Trim(ToWSTRING(name)), args }; #else std::string cmdline; char buf[1024]; @@ -154,6 +168,8 @@ inline WSTRING GetCurrentProcessCommandLine() { cmdline.append(buf, len); } + + fclose(fp); } std::string name; @@ -162,13 +178,14 @@ inline WSTRING GetCurrentProcessCommandLine() while (getline(tokens, tmp, '\0')) { name = name + " " + tmp; + args.push_back(Trim(ToWSTRING(tmp))); } - fclose(fp); - return Trim(ToWSTRING(name)); + return { Trim(ToWSTRING(name)), args }; + #endif - return EmptyWStr; + return {EmptyWStr, args}; } inline int GetPID() diff --git a/shared/src/native-src/string.cpp b/shared/src/native-src/string.cpp index 3c23aed177c9..739bbcae87f6 100644 --- a/shared/src/native-src/string.cpp +++ b/shared/src/native-src/string.cpp @@ -130,9 +130,19 @@ namespace shared { return str.size() >= suffix.size() && str.compare(str.size() - suffix.size(), suffix.size(), suffix) == 0; } + bool EndsWith(const WSTRING& str, const WSTRING& suffix) + { + return str.size() >= suffix.size() && str.compare(str.size() - suffix.size(), suffix.size(), suffix) == 0; + } + bool StartsWith(const std::string &str, const std::string &prefix) { return str.size() >= prefix.size() && str.compare(0, prefix.size(), prefix) == 0; } + bool StartsWith(const WSTRING &str, const WSTRING &prefix) + { + return str.size() >= prefix.size() && str.compare(0, prefix.size(), prefix) == 0; + } + } // namespace trace \ No newline at end of file diff --git a/shared/src/native-src/string.h b/shared/src/native-src/string.h index e9bdc611f81c..a411afba2fc2 100644 --- a/shared/src/native-src/string.h +++ b/shared/src/native-src/string.h @@ -57,9 +57,11 @@ WSTRING ToWSTRING(uint64_t i); bool TryParse(WSTRING const& s, int& result); bool EndsWith(const std::string& str, const std::string& suffix); - bool StartsWith(const std::string& str, const std::string& prefix); +bool EndsWith(const WSTRING& str, const WSTRING& suffix); +bool StartsWith(const WSTRING& str, const WSTRING& prefix); + template std::basic_string ReplaceString(std::basic_string subject, const std::basic_string& search, const std::basic_string& replace) diff --git a/tracer/src/Datadog.Tracer.Native/cor_profiler.cpp b/tracer/src/Datadog.Tracer.Native/cor_profiler.cpp index bfd2d17465d5..329f0ecb6bf7 100644 --- a/tracer/src/Datadog.Tracer.Native/cor_profiler.cpp +++ b/tracer/src/Datadog.Tracer.Native/cor_profiler.cpp @@ -71,7 +71,7 @@ HRESULT STDMETHODCALLTYPE CorProfiler::Initialize(IUnknown* cor_profiler_info_un const auto process_name = shared::GetCurrentProcessName(); Logger::Info("ProcessName: ", process_name); - const auto process_command_line = shared::GetCurrentProcessCommandLine(); + const auto [process_command_line , tokenized_command_line ] = GetCurrentProcessCommandLine(); Logger::Info("Process CommandLine: ", process_command_line); // CI visibility checks @@ -83,19 +83,13 @@ HRESULT STDMETHODCALLTYPE CorProfiler::Initialize(IUnknown* cor_profiler_info_un is_ci_visibility_enabled) { const auto isDotNetProcess = process_name == WStr("dotnet") || process_name == WStr("dotnet.exe"); - + const auto token_count = tokenized_command_line.size(); if (isDotNetProcess && + token_count > 1 && + tokenized_command_line[1] != WStr("test") && + // these are executed with exec, so we could check for that, but the + // below check is more conservative, so leaving at that process_command_line.find(WStr("testhost")) == WSTRING::npos && - process_command_line.find(WStr("dotnet test")) == WSTRING::npos && - process_command_line.find(WStr("dotnet\" test")) == WSTRING::npos && - process_command_line.find(WStr("dotnet' test")) == WSTRING::npos && - process_command_line.find(WStr("dotnet.exe test")) == WSTRING::npos && - process_command_line.find(WStr("dotnet.exe\" test")) == WSTRING::npos && - process_command_line.find(WStr("dotnet.exe' test")) == WSTRING::npos && - process_command_line.find(WStr("dotnet.dll test")) == WSTRING::npos && - process_command_line.find(WStr("dotnet.dll\" test")) == WSTRING::npos && - process_command_line.find(WStr("dotnet.dll' test")) == WSTRING::npos && - process_command_line.find(WStr(" test ")) == WSTRING::npos && process_command_line.find(WStr("datacollector")) == WSTRING::npos) { Logger::Info("The Tracer Profiler has been disabled because the process is running in CI Visibility " diff --git a/tracer/test/Datadog.Trace.ClrProfiler.IntegrationTests/InstrumentationTests.cs b/tracer/test/Datadog.Trace.ClrProfiler.IntegrationTests/InstrumentationTests.cs new file mode 100644 index 000000000000..53f4e2cde9b7 --- /dev/null +++ b/tracer/test/Datadog.Trace.ClrProfiler.IntegrationTests/InstrumentationTests.cs @@ -0,0 +1,180 @@ +// +// Unless explicitly stated otherwise all files in this repository are licensed under the Apache 2 License. +// This product includes software developed at Datadog (https://www.datadoghq.com/). Copyright 2017 Datadog, Inc. +// + +// There's nothing .NET 8 specific here, it's just that it's identical for all runtimes +// so there's not really any point in testing it repeatedly +#if NET8_0 +using System; +using System.IO; +using System.Text; +using System.Threading.Tasks; +using Datadog.Trace.Configuration; +using Datadog.Trace.TestHelpers; +using FluentAssertions; +using FluentAssertions.Execution; +using Xunit; +using Xunit.Abstractions; + +namespace Datadog.Trace.ClrProfiler.IntegrationTests +{ + public class InstrumentationTests : TestHelper + { + public InstrumentationTests(ITestOutputHelper output) + : base("Instrumentation.Tests", output) // Using a random name here, it doesn't matter + { + SetServiceVersion("1.0.0"); + } + + [SkippableFact] + [Trait("RunOnWindows", "True")] + public async Task DoesNotInstrumentDotnetBuild() + { + var workingDir = Path.Combine(Path.GetTempPath(), Path.GetFileNameWithoutExtension(Path.GetRandomFileName())); + Directory.CreateDirectory(workingDir); + + Output.WriteLine("Using workingDirectory: " + workingDir); + + using var agent = EnvironmentHelper.GetMockAgent(useTelemetry: true); + + var logDir = await RunDotnet("new console -n instrumentation_test -o . --no-restore"); + AssertNotInstrumented(agent, logDir); + + logDir = await RunDotnet("restore"); + AssertNotInstrumented(agent, logDir); + + logDir = await RunDotnet("build"); + AssertNotInstrumented(agent, logDir); + + logDir = await RunDotnet("publish"); + AssertNotInstrumented(agent, logDir); + + return; + + Task RunDotnet(string arguments) => RunDotnetCommand(workingDir, agent, arguments); + } + + [SkippableFact] + [Trait("RunOnWindows", "True")] + public async Task InstrumentsDotNetRun() + { + var workingDir = Path.Combine(Path.GetTempPath(), Path.GetFileNameWithoutExtension(Path.GetRandomFileName())); + Directory.CreateDirectory(workingDir); + + Output.WriteLine("Using workingDirectory: " + workingDir); + + using var agent = EnvironmentHelper.GetMockAgent(useTelemetry: true); + + var logDir = await RunDotnet("new console -n instrumentation_test -o . --no-restore"); + AssertNotInstrumented(agent, logDir); + + // this _should_ be instrumented so we expect managed data. + // we also expect telemetry, but we end the app so quickly there's a risk of flake + logDir = await RunDotnet("run"); + + using var scope = new AssertionScope(); + var allFiles = Directory.GetFiles(logDir); + AddFilesAsReportable(logDir, scope, allFiles); + allFiles.Should().Contain(filename => Path.GetFileName(filename).StartsWith("dotnet-tracer-managed-instrumentation_test-")); + agent.Telemetry.Should().NotBeEmpty(); + + return; + + Task RunDotnet(string arguments) => RunDotnetCommand(workingDir, agent, arguments); + } + + [SkippableFact] + [Trait("RunOnWindows", "True")] + public async Task InstrumentsDotNetTest() + { + var workingDir = Path.Combine(Path.GetTempPath(), Path.GetFileNameWithoutExtension(Path.GetRandomFileName())); + Directory.CreateDirectory(workingDir); + + Output.WriteLine("Using workingDirectory: " + workingDir); + + using var agent = EnvironmentHelper.GetMockAgent(useTelemetry: true); + + var logDir = await RunDotnet("new xunit -n instrumentation_test -o . --no-restore"); + AssertNotInstrumented(agent, logDir); + + // this _should_ be instrumented so we expect managed data. + // we also expect telemetry, but we end the app so quickly there's a risk of flake + logDir = await RunDotnet("test"); + + using var scope = new AssertionScope(); + var allFiles = Directory.GetFiles(logDir); + AddFilesAsReportable(logDir, scope, allFiles); + + // dotnet test might either of the following, so process name could be testhost or dotnet: + // - "C:\Users\andrew.lock\AppData\Local\Temp\upo3di0x\bin\Debug\net8.0\testhost.exe" --runtimeconfig "C:\Users\andrew.lock\AppData\Local\Temp\upo3di0x\bin\Debug\net8.0\instrumentation_test.runtimeconfig.json" --depsfile "C:\Users\andrew.lock\AppData\Local\Temp\upo3di0x\bin\Debug\net8.0\instrumentation_test.deps.json" --port 56961 --endpoint 127.0.0.1:056961 --role client --parentprocessid 71908 --telemetryoptedin false + // - /usr/share/dotnet/dotnet exec --runtimeconfig /tmp/yei4siaw/bin/Debug/net8.0/instrumentation_test.runtimeconfig.json --depsfile /tmp/yei4siaw/bin/Debug/net8.0/instrumentation_test.deps.json /tmp/yei4siaw/bin/Debug/net8.0/testhost.dll --port 44167 --endpoint 127.0.0.1:044167 --role client --parentprocessid 11522 --telemetryoptedin false + allFiles.Should() + .Contain( + filename => + Path.GetFileName(filename).StartsWith("dotnet-tracer-managed-testhost-") + || Path.GetFileName(filename).StartsWith("dotnet-tracer-managed-dotnet-")); + agent.Telemetry.Should().NotBeEmpty(); + + return; + + Task RunDotnet(string arguments) => RunDotnetCommand(workingDir, agent, arguments); + } + + private async Task RunDotnetCommand(string workingDirectory, MockTracerAgent mockTracerAgent, string arguments) + { + // Create unique folder for easier post-mortem analysis + var logDir = $"{workingDirectory}_logs_{Path.GetFileNameWithoutExtension(Path.GetRandomFileName())}"; + Output.WriteLine("Running: dotnet " + arguments); + Output.WriteLine("Using logDirectory: " + logDir); + + Directory.CreateDirectory(logDir); + SetEnvironmentVariable(ConfigurationKeys.LogDirectory, logDir); + + using var process = await ProfilerHelper.StartProcessWithProfiler( + executable: EnvironmentHelper.GetDotnetExe(), + EnvironmentHelper, + mockTracerAgent, + arguments, + workingDirectory: workingDirectory); // points to the sample project + + using var helper = new ProcessHelper(process); + + WaitForProcessResult(helper); + return logDir; + } + + private void AssertNotInstrumented(MockTracerAgent mockTracerAgent, string logDir) + { + // should have bailed out, but we still write logs to the native loader log + // _and_ the native tracer/profiler (because they're initialized), so important + // point is we don't have managed logs, and no spans or telemetry + using var scope = new AssertionScope(); + var allFiles = Directory.GetFiles(logDir); + AddFilesAsReportable(logDir, scope, allFiles); + + allFiles.Should().NotContain(filename => Path.GetFileName(filename).StartsWith("dotnet-tracer-managed-dotnet-")); + mockTracerAgent.Spans.Should().BeEmpty(); + mockTracerAgent.Telemetry.Should().BeEmpty(); + } + + private void AddFilesAsReportable(string logDir, AssertionScope scope, string[] allFiles) + { + scope.AddReportable( + $"Log files in {logDir}", + () => + { + var sb = new StringBuilder(); + foreach (var filename in allFiles) + { + sb.Append("File: ").AppendLine(filename); + sb.AppendLine("-----------------------"); + sb.AppendLine(File.ReadAllText(filename)); + } + + return sb.ToString(); + }); + } + } +} +#endif