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

Instrumentation does not work with dotnet CLI #1744

Closed
RassK opened this issue Dec 12, 2022 · 19 comments · Fixed by #2165
Closed

Instrumentation does not work with dotnet CLI #1744

RassK opened this issue Dec 12, 2022 · 19 comments · Fixed by #2165
Assignees
Milestone

Comments

@RassK
Copy link
Contributor

RassK commented Dec 12, 2022

[EDIT @pjanotti: the issue is fixed for versions after [v0.6.0-beta.1(]https://github.com/open-telemetry/opentelemetry-dotnet-instrumentation/releases/tag/v0.6.0-beta.1)]

Exception:

PS C:\Users\Administrator\Desktop\OTelConsole-NET6.0> dotnet run My.Simple.Console
Unhandled exception. System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation.
 ---> System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation.
 ---> System.TypeInitializationException: The type initializer for 'OpenTelemetry.AutoInstrumentation.Loader.Startup' threw an exception.
 ---> System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation.
 ---> System.IO.FileNotFoundException: Could not load file or assembly 'Microsoft.Extensions.Configuration.Abstractions, Version=7.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60'. The system cannot find the file specified.
File name: 'Microsoft.Extensions.Configuration.Abstractions, Version=7.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60'
   at Microsoft.Extensions.DependencyInjection.ProviderBuilderServiceCollectionExtensions.<>c.<AddOpenTelemetryProviderBuilderServices>b__2_0(IServiceProvider sp)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitFactory(FactoryCallSite factoryCallSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSiteMain(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitRootCache(ServiceCallSite callSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSite(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.Resolve(ServiceCallSite callSite, ServiceProviderEngineScope scope)
   at Microsoft.Extensions.DependencyInjection.ServiceProvider.CreateServiceAccessor(Type serviceType)
   at System.Collections.Concurrent.ConcurrentDictionary`2.GetOrAdd(TKey key, Func`2 valueFactory)
   at Microsoft.Extensions.DependencyInjection.ServiceProvider.GetService(Type serviceType, ServiceProviderEngineScope serviceProviderEngineScope)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.ServiceProviderEngineScope.GetService(Type serviceType)
   at Microsoft.Extensions.DependencyInjection.ServiceProviderServiceExtensions.GetRequiredService(IServiceProvider provider, Type serviceType)
   at Microsoft.Extensions.DependencyInjection.ServiceProviderServiceExtensions.GetRequiredService[T](IServiceProvider provider)
   at OpenTelemetry.Internal.ConfigurationExtensions.<>c__DisplayClass5_0`1.<RegisterOptionsFactory>b__0(IServiceProvider sp)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitFactory(FactoryCallSite factoryCallSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSiteMain(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitRootCache(ServiceCallSite callSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSite(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitConstructor(ConstructorCallSite constructorCallSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSiteMain(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitRootCache(ServiceCallSite callSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSite(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.Resolve(ServiceCallSite callSite, ServiceProviderEngineScope scope)
   at Microsoft.Extensions.DependencyInjection.ServiceProvider.CreateServiceAccessor(Type serviceType)
   at System.Collections.Concurrent.ConcurrentDictionary`2.GetOrAdd(TKey key, Func`2 valueFactory)
   at Microsoft.Extensions.DependencyInjection.ServiceProvider.GetService(Type serviceType, ServiceProviderEngineScope serviceProviderEngineScope)
   at Microsoft.Extensions.DependencyInjection.ServiceProvider.GetService(Type serviceType)
   at Microsoft.Extensions.DependencyInjection.ServiceProviderServiceExtensions.GetRequiredService(IServiceProvider provider, Type serviceType)
   at Microsoft.Extensions.DependencyInjection.ServiceProviderServiceExtensions.GetRequiredService[T](IServiceProvider provider)
   at OpenTelemetry.Trace.OtlpTraceExporterHelperExtensions.<>c__DisplayClass2_0.<AddOtlpExporter>b__1(IServiceProvider sp, TracerProviderBuilder builder)
   at OpenTelemetry.ProviderBuilderServiceCollectionCallbackHelper`3.<>c__DisplayClass0_0.<RegisterConfigureBuilderCallback>b__0(IServiceProvider sp, TState state)
   at OpenTelemetry.ProviderBuilderServiceCollectionCallbackHelper`3.ConfigureProviderBuilderStateCallbackRegistration.Configure(IServiceProvider serviceProvider, TState state)
   at OpenTelemetry.ProviderBuilderServiceCollectionCallbackHelper`3.InvokeRegisteredConfigureStateCallbacks(IServiceProvider serviceProvider, TState state)
   at OpenTelemetry.Trace.TracerProviderSdk..ctor(IServiceProvider serviceProvider, Boolean ownsServiceProvider)
   at OpenTelemetry.Trace.TracerProviderBuilderBase.Build()
   at OpenTelemetry.Trace.TracerProviderBuilderBase.InvokeBuild()
   at OpenTelemetry.Trace.TracerProviderBuilderExtensions.Build(TracerProviderBuilder tracerProviderBuilder)
   at OpenTelemetry.AutoInstrumentation.Instrumentation.Initialize() in F:\Dev\forks\rassk\opentelemetry-dotnet-instrumentation\src\OpenTelemetry.AutoInstrumentation\Instrumentation.cs:line 121
   at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
   at System.Reflection.MethodInvoker.Invoke(Object obj, IntPtr* args, BindingFlags invokeAttr)
   --- End of inner exception stack trace ---
   at System.Reflection.MethodInvoker.Invoke(Object obj, IntPtr* args, BindingFlags invokeAttr)
   at System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture)
   at System.Reflection.MethodBase.Invoke(Object obj, Object[] parameters)
   at OpenTelemetry.AutoInstrumentation.Loader.Startup.TryLoadManagedAssembly() in F:\Dev\forks\rassk\opentelemetry-dotnet-instrumentation\src\OpenTelemetry.AutoInstrumentation.Loader\Startup.cs:line 71
   at OpenTelemetry.AutoInstrumentation.Loader.Startup..cctor() in F:\Dev\forks\rassk\opentelemetry-dotnet-instrumentation\src\OpenTelemetry.AutoInstrumentation.Loader\Startup.cs:line 47
   --- End of inner exception stack trace ---
   at OpenTelemetry.AutoInstrumentation.Loader.Startup..ctor()
   at System.RuntimeType.CreateInstanceDefaultCtor(Boolean publicOnly, Boolean wrapExceptions)
   --- End of inner exception stack trace ---
   at System.RuntimeType.CreateInstanceDefaultCtor(Boolean publicOnly, Boolean wrapExceptions)
   at System.Activator.CreateInstance(Type type, Boolean nonPublic, Boolean wrapExceptions)
   at System.RuntimeType.CreateInstanceImpl(BindingFlags bindingAttr, Binder binder, Object[] args, CultureInfo culture)
   at System.Activator.CreateInstance(Type type, BindingFlags bindingAttr, Binder binder, Object[] args, CultureInfo culture, Object[] activationAttributes)
   at System.Reflection.Assembly.CreateInstance(String typeName, Boolean ignoreCase, BindingFlags bindingAttr, Binder binder, Object[] args, CultureInfo culture, Object[] activationAttributes)
   at System.Reflection.Assembly.CreateInstance(String typeName)
   at StartupHook.Initialize() in F:\Dev\forks\rassk\opentelemetry-dotnet-instrumentation\src\OpenTelemetry.AutoInstrumentation.StartupHook\StartupHook.cs:line 75
   at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
   at System.Reflection.MethodInvoker.Invoke(Object obj, IntPtr* args, BindingFlags invokeAttr)
   --- End of inner exception stack trace ---
   at System.Reflection.MethodInvoker.Invoke(Object obj, IntPtr* args, BindingFlags invokeAttr)
   at System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture)
   at System.Reflection.MethodBase.Invoke(Object obj, Object[] parameters)
   at System.StartupHookProvider.CallStartupHook(StartupHookNameOrPath startupHook)
   at System.StartupHookProvider.ProcessStartupHooks()

Test App:

using System.Diagnostics;

namespace My.Simple.ConsoleApp;

internal class Program
{
    private static ActivitySource MySource = new ActivitySource("My.Simple.Console");

    public static void Main(string[] args)
    {
        Console.WriteLine("Hello My.Simple.ConsoleApp");

        using (var activity = MySource.StartActivity("Main"))
        {
            Console.WriteLine("Inside activity create");

            activity?.AddTag("my.custom.tag", "my.simple.consoleapp");
        }

        Console.WriteLine("All done");
    }
}
<Project Sdk="Microsoft.NET.Sdk">

	<PropertyGroup>
		<OutputType>exe</OutputType>
		<TargetFramework>net6.0</TargetFramework>
		<ImplicitUsings>enable</ImplicitUsings>
		<Nullable>enable</Nullable>
	</PropertyGroup>

	<ItemGroup>
		<PackageReference Include="Microsoft.Extensions.Configuration.Abstractions" Version="7.0.0" />
		<PackageReference Include="System.Diagnostics.DiagnosticSource" Version="7.0.0" />
	</ItemGroup>

</Project>
@RassK
Copy link
Contributor Author

RassK commented Dec 12, 2022

I guess it's the same thing as previously was with dotnet help, but we did not fix it.

@pellared
Copy link
Member

pellared commented Dec 12, 2022

From #1699 (comment)

It [dotnet.exe] is a self-contained executable. Our implementation does not work for self-contained apps as they don't support AdditionalDeps.

@RassK
Copy link
Contributor Author

RassK commented Dec 12, 2022

Setting this helped.
$env:OTEL_DOTNET_AUTO_EXCLUDE_PROCESSES = "dotnet,dotnet.exe"

I think we should consider baking some well known exceptions into our solution.

@pjanotti pjanotti added this to the 0.5.1 milestone Dec 14, 2022
@RassK
Copy link
Contributor Author

RassK commented Dec 15, 2022

SIG: Docker templates are used to do "dotnet myapp.dll", so blocking this command will be problematic.

@pellared
Copy link
Member

pellared commented Dec 29, 2022

@RassK Do you think adding adding a section about dotnet run in "Troubleshooting" would help?

@RassK
Copy link
Contributor Author

RassK commented Jan 2, 2023

@RassK Do you think adding adding a section about dotnet run in "Troubleshooting" would help?

Needs further investigations what are the workarounds (eg compiling .exe and running directly that instead of dotnet smth)

@nrcventura
Copy link
Member

SIG: Docker templates are used to do "dotnet myapp.dll", so blocking this command will be problematic.

I added the exclude process support to the startup hook specifically for this scenario, and adding dotnet,dotnet.exe to the exclude list allowed dotnet myapp.dll to work back then. I remember that command resulting in the startup hook executing twice. Once for dotnet.exe, and then for myapp.dll.

@pjanotti
Copy link
Contributor

pjanotti commented Jan 24, 2023

Skip from StartupHook is working correctly regarding the excluded processes. However, it seems that we should let the StartupHook deal with DOTNET_ADDITIONAL_DEPS and DOTNET_SHARED_STORE to avoid the error above. Otherwise, it becomes impossible to use dotnet CLI. That said per my experiments we are not out of the woods even regarding dotnet run because the application itself is still crashing due to missing dependencies.

@pjanotti pjanotti changed the title Instrumentation does not work with dotnet run Instrumentation does not work with dotnet CLI Jan 31, 2023
@pjanotti pjanotti self-assigned this Jan 31, 2023
@pellared pellared mentioned this issue Feb 3, 2023
5 tasks
@pellared
Copy link
Member

pellared commented Feb 3, 2023

After merging #2157 it is better, but I still managed to repro an issue using dotnet.

Test env

Testing 908504a on Windows with

$ dotnet --version
7.0.102

Repro

# it is important to make sure to have a clean repository before testing
git clean -fxd
nuke

# instrument current session
export OTEL_DOTNET_AUTO_HOME=bin/tracer-home
. ./instrument.sh

# run unit tests
cd test/OpenTelemetry.AutoInstrumentation.Tests
dotnet test

Errors listed in the output (the test were not run):

Test run for C:\Users\rpajak\repos\opentelemetry-dotnet-instrumentation\test\OpenTelemetry.AutoInstrumentation.Tests\bin\Debug\net7.0\OpenTelemetry.AutoInstrumentation.Tests.dll (.NETCoreApp,Version=v7.0)
Error:
  An assembly specified in the application dependencies manifest (OpenTelemetry.AutoInstrumentation.AdditionalDeps.deps.json) was not found:
    package: 'DnsClient', version: '1.4.0'
    path: 'lib/netstandard2.1/DnsClient.dll'
Test run for C:\Users\rpajak\repos\opentelemetry-dotnet-instrumentation\test\OpenTelemetry.AutoInstrumentation.Tests\bin\Debug\net6.0\OpenTelemetry.AutoInstrumentation.Tests.dll (.NETCoreApp,Version=v6.0)
Error:
  An assembly specified in the application dependencies manifest (OpenTelemetry.AutoInstrumentation.AdditionalDeps.deps.json) was not found:
    package: 'DnsClient', version: '1.4.0'
    path: 'lib/netstandard2.1/DnsClient.dll'
Test run for C:\Users\rpajak\repos\opentelemetry-dotnet-instrumentation\test\OpenTelemetry.AutoInstrumentation.Tests\bin\Debug\net462\OpenTelemetry.AutoInstrumentation.Tests.dll (.NETFramework,Version=v4.6.2)
Error:
  An assembly specified in the application dependencies manifest (OpenTelemetry.AutoInstrumentation.AdditionalDeps.deps.json) was not found:
    package: 'DnsClient', version: '1.4.0'
    path: 'lib/netstandard2.1/DnsClient.dll'

It looks like #2036 (comment)

I also want to note that dotnet build does not always works fine. I encountered some issues with Roslyn, but I cannot reproduce always them. Here is an example:

cd - # return to root
cd test/test-applications/integrations/TestApplication.Smoke
dotnet run -f net7.0

This is the error I get:

C:\Program Files\dotnet\sdk\7.0.102\Roslyn\Microsoft.CSharp.Core.targets(79,5): error : Error: [C:\Users\rpajak\repos\opentelemetry-dotnet-instrumentation\test\test-applications\integrations\depende
ncy-libs\TestApplication.Shared\TestApplication.Shared.csproj::TargetFramework=net7.0]
C:\Program Files\dotnet\sdk\7.0.102\Roslyn\Microsoft.CSharp.Core.targets(79,5): error :   An assembly specified in the application dependencies manifest (OpenTelemetry.AutoInstrumentation.Additional 
Deps.deps.json) was not found: [C:\Users\rpajak\repos\opentelemetry-dotnet-instrumentation\test\test-applications\integrations\dependency-libs\TestApplication.Shared\TestApplication.Shared.csproj::T 
argetFramework=net7.0]
C:\Program Files\dotnet\sdk\7.0.102\Roslyn\Microsoft.CSharp.Core.targets(79,5): error :     package: 'Microsoft.Extensions.Configuration', version: '7.0.0' [C:\Users\rpajak\repos\opentelemetry-dotne 
t-instrumentation\test\test-applications\integrations\dependency-libs\TestApplication.Shared\TestApplication.Shared.csproj::TargetFramework=net7.0]
C:\Program Files\dotnet\sdk\7.0.102\Roslyn\Microsoft.CSharp.Core.targets(79,5): error :     path: 'lib/net7.0/Microsoft.Extensions.Configuration.dll' [C:\Users\rpajak\repos\opentelemetry-dotnet-inst 
rumentation\test\test-applications\integrations\dependency-libs\TestApplication.Shared\TestApplication.Shared.csproj::TargetFramework=net7.0]

The build failed. Fix the build errors and run again.

@pjanotti
Copy link
Contributor

pjanotti commented Feb 3, 2023

I also got an error trying with the steps that you described @pellared on Windows using git-bash to run the scripts:

# run unit tests
cd test/OpenTelemetry.AutoInstrumentation.Tests
dotnet test

but notice that the error messages are the ones that you got for the second command (I didn't try that one yet):

dotnet test
  Determining projects to restore...
  All projects are up-to-date for restore.
C:\Program Files\dotnet\sdk\7.0.101\Roslyn\Microsoft.CSharp.Core.targets(79,5): error : Error: [C:\src\otel\dotnet\auto\src\OpenTelemetry.AutoInstrumentation\OpenTelemetry.AutoInstrumentation.csproj::TargetFramework=net6.0]
C:\Program Files\dotnet\sdk\7.0.101\Roslyn\Microsoft.CSharp.Core.targets(79,5): error :   An assembly specified in the application dependencies manifest (OpenTelemetry.AutoInstrumentation.AdditionalDeps.deps.json) was not found: [C:\src\otel\dotnet\auto\src\OpenTelemetry.AutoInstrumentation\OpenTelemetry.AutoInstrumentation.csproj::TargetFramework=net6.0]
C:\Program Files\dotnet\sdk\7.0.101\Roslyn\Microsoft.CSharp.Core.targets(79,5): error :     package: 'Microsoft.Extensions.Configuration', version: '7.0.0' [C:\src\otel\dotnet\auto\src\OpenTelemetry.AutoInstrumentation\OpenTelemetry.AutoInstrumentation.csproj::TargetFramework=net6.0]
C:\Program Files\dotnet\sdk\7.0.101\Roslyn\Microsoft.CSharp.Core.targets(79,5): error :     path: 'lib/net7.0/Microsoft.Extensions.Configuration.dll' [C:\src\otel\dotnet\auto\src\OpenTelemetry.AutoInstrumentation\OpenTelemetry.AutoInstrumentation.csproj::TargetFramework=net6.0]
C:\Program Files\dotnet\sdk\7.0.101\Roslyn\Microsoft.CSharp.Core.targets(79,5): error : Error: [C:\src\otel\dotnet\auto\src\OpenTelemetry.AutoInstrumentation\OpenTelemetry.AutoInstrumentation.csproj::TargetFramework=net462]
C:\Program Files\dotnet\sdk\7.0.101\Roslyn\Microsoft.CSharp.Core.targets(79,5): error :   An assembly specified in the application dependencies manifest (OpenTelemetry.AutoInstrumentation.AdditionalDeps.deps.json) was not found: [C:\src\otel\dotnet\auto\src\OpenTelemetry.AutoInstrumentation\OpenTelemetry.AutoInstrumentation.csproj::TargetFramework=net462]
C:\Program Files\dotnet\sdk\7.0.101\Roslyn\Microsoft.CSharp.Core.targets(79,5): error :     package: 'Microsoft.Extensions.Configuration', version: '7.0.0' [C:\src\otel\dotnet\auto\src\OpenTelemetry.AutoInstrumentation\OpenTelemetry.AutoInstrumentation.csproj::TargetFramework=net462]
C:\Program Files\dotnet\sdk\7.0.101\Roslyn\Microsoft.CSharp.Core.targets(79,5): error :     path: 'lib/net7.0/Microsoft.Extensions.Configuration.dll' [C:\src\otel\dotnet\auto\src\OpenTelemetry.AutoInstrumentation\OpenTelemetry.AutoInstrumentation.csproj::TargetFramework=net462]

@pjanotti
Copy link
Contributor

pjanotti commented Feb 3, 2023

Same error as @pellared when trying to run the smoke test app.

@rajkumar-rangaraj
Copy link
Contributor

rajkumar-rangaraj commented Feb 3, 2023

I could recreate the issue on dotnet test.

Error:
  An assembly specified in the application dependencies manifest (OpenTelemetry.AutoInstrumentation.AdditionalDeps.deps.json) was not found:
    package: 'DnsClient', version: '1.4.0'
    path: 'lib/netstandard2.1/DnsClient.dll'

Issue gets resolved, if I manually reset the environment variables to below values.

export DOTNET_STARTUP_HOOKS=/d/opentelemetry-dotnet-instrumentation/bin/tracer-home/net/OpenTelemetry.AutoInstrumentation.StartupHook.dll
export DOTNET_SHARED_STORE=/d/opentelemetry-dotnet-instrumentation/bin/tracer-home/store
export DOTNET_ADDITIONAL_DEPS=/d/opentelemetry-dotnet-instrumentation/bin/tracer-home/AdditionalDeps
export ASPNETCORE_HOSTINGSTARTUPASSEMBLIES=OpenTelemetry.AutoInstrumentation.AspNetCoreBootstrapper
export OTEL_DOTNET_AUTO_HOME=/d/opentelemetry-dotnet-instrumentation/bin/tracer-home
export OTEL_DOTNET_AUTO_TRACES_CONSOLE_EXPORTER_ENABLED=true
export OTEL_DOTNET_AUTO_METRICS_CONSOLE_EXPORTER_ENABLED=true
export OTEL_DOTNET_AUTO_LOGS_CONSOLE_EXPORTER_ENABLED=true
export OTEL_SERVICE_NAME=DemoService
export OTEL_DOTNET_AUTO_DEBUG=true
export OTEL_DOTNET_AUTO_LOG_DIRECTORY=/C/temp/

Collected dotnet trace to check why we ran into an issue. In the non-working case shared store environment variable was not honored. I don't know the reason for it. Resetting only shared store environment variable did not solve an issue. I had to reset all the environment variables like above to get it working.

Non-Working

Found registered install location 'C:\Program Files\dotnet\'.
-- arguments_t: host_path='C:\Program Files\dotnet\dotnet.exe' app_root='C:\Program Files\dotnet\sdk\7.0.102\' deps='C:\Program Files\dotnet\sdk\7.0.102\dotnet.deps.json' core_svc='C:\Program Files (x86)\coreservicing' mgd_app='C:\Program Files\dotnet\sdk\7.0.102\dotnet.dll'
-- arguments_t: dotnet shared store: 'C:\Program Files\dotnet\store\x64\net7.0'
-- arguments_t: global shared store: 'C:\Program Files\dotnet\store\x64\net7.0'

Working

Found registered install location 'C:\Program Files\dotnet\'.
-- arguments_t: host_path='C:\Program Files\dotnet\dotnet.exe' app_root='C:\Program Files\dotnet\sdk\7.0.102\' deps='C:\Program Files\dotnet\sdk\7.0.102\dotnet.deps.json' core_svc='C:\Program Files (x86)\coreservicing' mgd_app='C:\Program Files\dotnet\sdk\7.0.102\dotnet.dll'
-- arguments_t: env shared store: 'D:\temp\Azure.OpenTelemetry\store\x64\net7.0'
-- arguments_t: dotnet shared store: 'C:\Program Files\dotnet\store\x64\net7.0'
-- arguments_t: global shared store: 'C:\Program Files\dotnet\store\x64\net7.0'

Below were the environmental variable set, just by running instrument.sh.

COR_PROFILER={918728DD-259F-4A6A-AC2B-B85E1B658318}
COR_PROFILER_PATH_64=D:\opentelemetry-dotnet-instrumentation\bin\tracer-home/win-x64/OpenTelemetry.AutoInstrumentation.Native.dll
DOTNET_SHARED_STORE=D:\opentelemetry-dotnet-instrumentation\bin\tracer-home\store
CORECLR_PROFILER={918728DD-259F-4A6A-AC2B-B85E1B658318}
COR_ENABLE_PROFILING=1
COR_PROFILER_PATH_32=D:\opentelemetry-dotnet-instrumentation\bin\tracer-home/win-x86/OpenTelemetry.AutoInstrumentation.Native.dll
OTEL_DOTNET_AUTO_INTEGRATIONS_FILE=D:\opentelemetry-dotnet-instrumentation\bin\tracer-home/integrations.json
CORECLR_PROFILER_PATH_64=D:\opentelemetry-dotnet-instrumentation\bin\tracer-home/win-x64/OpenTelemetry.AutoInstrumentation.Native.dll
CORECLR_ENABLE_PROFILING=1
DOTNET_ADDITIONAL_DEPS=D:\opentelemetry-dotnet-instrumentation\bin\tracer-home/AdditionalDeps
CORECLR_PROFILER_PATH_32=D:\opentelemetry-dotnet-instrumentation\bin\tracer-home/win-x86/OpenTelemetry.AutoInstrumentation.Native.dll
DOTNET_STARTUP_HOOKS=D:\opentelemetry-dotnet-instrumentation\bin\tracer-home/net/OpenTelemetry.AutoInstrumentation.StartupHook.dll
OTEL_DOTNET_AUTO_HOME=D:\opentelemetry-dotnet-instrumentation\bin\tracer-home
DOTNET_HOST_PATH=C:\Program Files\dotnet\dotnet.exe

Further analysis is needed to understand what is an issue with instrument.sh set environment variables.

@pellared
Copy link
Member

pellared commented Feb 6, 2023

Related issue #2167 . It looks like the problem is not only with dotnet. Maybe it is a bug in the .NET runtime? 🤔

@pellared
Copy link
Member

pellared commented Feb 6, 2023

but notice that the error messages are the ones that you got for the second command (I didn't try that one yet):

For me these error messages were not deterministic. But I remember I had it for dotnet test as well at least once.

@pjanotti
Copy link
Contributor

pjanotti commented Feb 7, 2023

@pellared @rajkumar-rangaraj here is a case where now it is a bit clear what is happening. In this case, I'm setting only DOTNET_ADDITIONAL_DEPS and DOTNET_SHARED_STORE to keep it simple.

If I run a git clean -fdx and then dotnet nuke dotnet nuke Clean BuildTracer CompileManagedTests CompileMocks PublishMocks PublishIisTestApplications a VBCSCompiler "server" is started and kept running in the background, e.g.:

PS C:\src> Get-WmiObject Win32_Process -Filter "name = 'dotnet.exe'" | Select CommandLine | fl
  ...
Line : @{CommandLine="C:\Program Files\dotnet\dotnet.exe" exec "C:\Program Files\dotnet\sdk\7.0.101\Roslyn\bincore\VBCSCompiler.dll"
       "-pipename:qG18S59RleExn1Gpc05nb8cU695tnOu2clqkRpjneyY"}

Then dotnet build, dotnet run and other commands that use the VBCSCompiler work fine since a new one doesn't need to be launched. However, if I kill the VBCSCompiler "server", then we hit the error about AdditionalDeps:

c:\src\spikes\dotnet\DotNetCliTest>dotnet build
MSBuild version 17.4.0+18d5aef85 for .NET
  Determining projects to restore...
  All projects are up-to-date for restore.
C:\Program Files\dotnet\sdk\7.0.101\Roslyn\Microsoft.CSharp.Core.targets(79,5): error : Error: [c:\src\spikes\dotnet\DotNetCliTest\DotNetCliTest.csproj]
C:\Program Files\dotnet\sdk\7.0.101\Roslyn\Microsoft.CSharp.Core.targets(79,5): error :   An assembly specified in the application dependencies manifest (OpenTele
metry.AutoInstrumentation.AdditionalDeps.deps.json) was not found: [c:\src\spikes\dotnet\DotNetCliTest\DotNetCliTest.csproj]
C:\Program Files\dotnet\sdk\7.0.101\Roslyn\Microsoft.CSharp.Core.targets(79,5): error :     package: 'Microsoft.Extensions.Configuration', version: '7.0.0' [c:\sr
c\spikes\dotnet\DotNetCliTest\DotNetCliTest.csproj]
C:\Program Files\dotnet\sdk\7.0.101\Roslyn\Microsoft.CSharp.Core.targets(79,5): error :     path: 'lib/net7.0/Microsoft.Extensions.Configuration.dll' [c:\src\spik
es\dotnet\DotNetCliTest\DotNetCliTest.csproj]

Build FAILED.

C:\Program Files\dotnet\sdk\7.0.101\Roslyn\Microsoft.CSharp.Core.targets(79,5): error : Error: [c:\src\spikes\dotnet\DotNetCliTest\DotNetCliTest.csproj]
C:\Program Files\dotnet\sdk\7.0.101\Roslyn\Microsoft.CSharp.Core.targets(79,5): error :   An assembly specified in the application dependencies manifest (OpenTele
metry.AutoInstrumentation.AdditionalDeps.deps.json) was not found: [c:\src\spikes\dotnet\DotNetCliTest\DotNetCliTest.csproj]
C:\Program Files\dotnet\sdk\7.0.101\Roslyn\Microsoft.CSharp.Core.targets(79,5): error :     package: 'Microsoft.Extensions.Configuration', version: '7.0.0' [c:\sr
c\spikes\dotnet\DotNetCliTest\DotNetCliTest.csproj]
C:\Program Files\dotnet\sdk\7.0.101\Roslyn\Microsoft.CSharp.Core.targets(79,5): error :     path: 'lib/net7.0/Microsoft.Extensions.Configuration.dll' [c:\src\spik
es\dotnet\DotNetCliTest\DotNetCliTest.csproj]
    0 Warning(s)
    4 Error(s)

Time Elapsed 00:00:21.03

This error happens before there is any attempt to even load the StartupHook when dotnet CLI tries to launch VBCSCompiler. The error happens when the hostpolicy tries to validate the Trusted Platform Assemblies (TPA) and tries to validate an assembly from the project AdditionalDeps.

I'm not sure about the criteria when a VBCSCompiler server is created, but, if there is one running for the project that you are targeting I can run dotnet CLI fine for the typical commands. This seems to be what is happening in the case of PR #2165. It seems that if the VBCSCompiler process is inactive for some time it exits on its own, triggering the error above.

@pjanotti
Copy link
Contributor

pjanotti commented Feb 7, 2023

We may have to consider not using the AdditionalDeps and loading the dependencies via the StartupHook, see here. That said I'm not sure how that would affect assemblies in the TPA list. Anyway, something that we may have to try.

@pjanotti
Copy link
Contributor

pjanotti commented Feb 7, 2023

Using the corehost tracing, it gives some hope that perhaps the error is actually in our AdditionalDeps. In our shared store the missing assembly is located at:

store\x64\net6.0\microsoft.extensions.configuration\7.0.0\lib\net6.0\Microsoft.Extensions.Configuration.dll

However, it is being probed at

store\x64\net6.0\microsoft.extensions.configuration\7.0.0\lib\net7.0\Microsoft.Extensions.Configuration.dll

Notice the different folders just before the assembly: the store is net6.0 and the probe is done at net7.0.

@pjanotti
Copy link
Contributor

pjanotti commented Feb 7, 2023

I suppose the probe path is due to the respective runtimeconfig.json which has net6.0 as TFM but framework as 7.0.1:

{
  "runtimeOptions": {
    "tfm": "net6.0",
    "framework": {
      "name": "Microsoft.NETCore.App",
      "version": "7.0.1"
    },
    "rollForwardOnNoCandidateFx": 2,
    "configProperties": {
      "System.GC.Server": true,
      "System.Reflection.Metadata.MetadataUpdater.IsSupported": false
    }
  }
}

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
5 participants