grafana / pyroscope-dotnet

Dotnet profiler
Apache License 2.0
24 stars 6 forks source link

When running Pyroscope on Docker getting LoadDynamicLibrary: Error loading dynamic library '/dotnet/Datadog.Trace.ClrProfiler.Native.so': /dotnet/Datadog.Trace.ClrProfiler.Native.so: cannot open shared object file: No such file or directory #39

Closed kamilchodola closed 11 months ago

kamilchodola commented 1 year ago

Started a container with configuration as such one:

WORKDIR /dotnet

RUN apt-get update && apt-get install -y wget tar RUN wget -qO- https://github.com/grafana/pyroscope-dotnet/releases/download/v0.8.8-pyroscope/pyroscope.0.8.8-glibc-x86_64.tar.gz \ | tar xvz

ENV CORECLR_ENABLE_PROFILING=1 ENV CORECLR_PROFILER={BD1A650D-AC5D-4896-B64F-D6FA25D6B26A} ENV CORECLR_PROFILER_PATH=/dotnet/Pyroscope.Profiler.Native.so ENV LD_PRELOAD=/dotnet/Pyroscope.Linux.ApiWrapper.x64.so

ENV PYROSCOPE_APPLICATION_NAME=APPNAME ENV PYROSCOPE_SERVER_ADDRESS=URLHERE ENV PYROSCOPE_LOG_LEVEL=debug ENV PYROSCOPE_PROFILING_ENABLED=1 ENV PYROSCOPE_PROFILING_ALLOCATION_ENABLED=true ENV PYROSCOPE_PROFILING_CONTENTION_ENABLED=true ENV PYROSCOPE_PROFILING_EXCEPTION_ENABLED=true

And when running container (where also detail on how to run application is included) I'm getting Pyroscope logs but with reference to DataDog file:

[2023-08-22 10:37:38.471 | info | PId: 1 | TId: 1] Profiler DLL loaded.
[2023-08-22 10:37:38.471 | info | PId: 1 | TId: 1] Pointer size: 64 bits.
[2023-08-22 10:37:38.471 | info | PId: 1 | TId: 1] Value "1" for "DD_PROFILING_ENABLED" environment variable. Enable = 1
[2023-08-22 10:37:38.471 | info | PId: 1 | TId: 1] DllGetClassObject(): Returning an instance of CorProfilerCallbackFactory (hr=0x0)
[2023-08-22 10:37:38.472 | info | PId: 1 | TId: 1] CorProfilerCallback is initializing.
[2023-08-22 10:37:38.472 | info | PId: 1 | TId: 1] No "DD_TRACE_DEBUG" environment variable has been found. Enable debug log = 0 (default).
[2023-08-22 10:37:38.472 | info | PId: 1 | TId: 1] Environment variables:
[2023-08-22 10:37:38.472 | info | PId: 1 | TId: 1] ICorProfilerInfo13 available. Profiling API compatibility: .NET Core 7.0 or later.
[2023-08-22 10:37:38.472 | info | PId: 1 | TId: 1] Initializing the Profiler: Reported runtime version : { clrInstanceId: 0, runtimeType:CORE_CLR, majorVersion: 7, minorVersion: 0, buildNumber: 10, qfeVersion: 0 }.
[2023-08-22 10:37:38.472 | info | PId: 1 | TId: 1] No "DD_INTERNAL_OPERATIONAL_METRICS_ENABLED" environment variable has been found. Default: Operational metrics disabled.
[2023-08-22 10:37:38.472 | info | PId: 1 | TId: 1] ProfilerSignalManager::SetupSignalHandler: Successfully setup signal handler for SIGUSR1 signal.
[2023-08-22 10:37:38.472 | info | PId: 1 | TId: 1] ThreadsCpuManager started successfully.
[2023-08-22 10:37:38.472 | info | PId: 1 | TId: 1] ManagedThreadList started successfully.
[2023-08-22 10:37:38.472 | info | PId: 1 | TId: 1] ManagedThreadList started successfully.
**[2023-08-22 10:37:38.472 | warning | PId: 1 | TId: 1] LoadDynamicLibrary: Error loading dynamic library '/dotnet/Datadog.Trace.ClrProfiler.Native.so': /dotnet/Datadog.Trace.ClrProfiler.Native.so: cannot open shared object file: No such file or directory
[2023-08-22 10:37:38.472 | warning | PId: 1 | TId: 1] The RuntimeID store service couldn't load the native proxy.**
[2023-08-22 10:37:38.472 | info | PId: 1 | TId: 1] RuntimeID Store started successfully.
[2023-08-22 10:37:38.472 | info | PId: 1 | TId: 1] CpuTimeProvider started successfully.
[2023-08-22 10:37:38.472 | info | PId: 1 | TId: 1] ExceptionsProvider started successfully.
[2023-08-22 10:37:38.472 | info | PId: 1 | TId: 1] AllocationsProvider started successfully.
[2023-08-22 10:37:38.472 | info | PId: 1 | TId: 1] ContentionProvider started successfully.
[2023-08-22 10:37:38.472 | info | PId: 1 | TId: 1] Processor cores = 20
[2023-08-22 10:37:38.472 | info | PId: 1 | TId: 1] CPU and wall time sampling period = 9 ms
raphaelquati commented 1 year ago

hi @kamilchodola ,

I've setup Pyroscope server yesterday, and change my Docker file (Visual Studio generated it) this way:

FROM mcr.microsoft.com/dotnet/sdk:7.0 AS build
WORKDIR /src
COPY ["NuGet.config", "."]
COPY ["Test/Test.csproj", "Test/"]
RUN dotnet restore "Test/Test.csproj"
COPY . .
WORKDIR "/src/Test"
RUN dotnet build "Test.csproj" -c Release -o /app/build

FROM build AS publish
RUN dotnet publish "Test.csproj" -c Release -o /app/publish /p:UseAppHost=false

FROM base AS final
WORKDIR /app
COPY --from=publish /app/publish .
<--- INSERTED
COPY --from=pyroscope/pyroscope-dotnet:0.8.8-glibc /Pyroscope.Profiler.Native.so ./Pyroscope.Profiler.Native.so
COPY --from=pyroscope/pyroscope-dotnet:0.8.8-glibc /Pyroscope.Linux.ApiWrapper.x64.so 
./Pyroscope.Linux.ApiWrapper.x64.so
<--- INSERTED

ENTRYPOINT ["dotnet", "Test.dll"]

EnvVars configured:

PYROSCOPE_SERVER_ADDRESS=http://pyroscope-distributor:4040
PYROSCOPE_PROFILING_ALLOCATION_ENABLED=1
PYROSCOPE_PROFILING_CONTENTION_ENABLED=1
PYROSCOPE_PROFILING_CPU_ENABLED=1
PYROSCOPE_PROFILING_ENABLED=1
PYROSCOPE_PROFILING_EXCEPTION_ENABLED=1
PYROSCOPE_PROFILING_WALLTIME_ENABLED=1
CORECLR_ENABLE_PROFILING=1
CORECLR_PROFILER='{BD1A650D-AC5D-4896-B64F-D6FA25D6B26A}'
CORECLR_PROFILER_PATH=/app/Pyroscope.Profiler.Native.so
LD_PRELOAD=/app/Pyroscope.Linux.ApiWrapper.x64.so

Log:

2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.152 | info | PId: 1 | TId: 1] Profiler DLL loaded.
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.152 | info | PId: 1 | TId: 1] Pointer size: 64 bits.
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.152 | info | PId: 1 | TId: 1] Value "1" for "DD_PROFILING_ENABLED" environment variable. Enable = 1
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.152 | info | PId: 1 | TId: 1] DllGetClassObject(): Returning an instance of CorProfilerCallbackFactory (hr=0x0)
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.152 | info | PId: 1 | TId: 1] CorProfilerCallback is initializing.
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.152 | info | PId: 1 | TId: 1] No "DD_TRACE_DEBUG" environment variable has been found. Enable debug log = 0 (default).
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.152 | info | PId: 1 | TId: 1] Environment variables:
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.153 | info | PId: 1 | TId: 1] ICorProfilerInfo13 available. Profiling API compatibility: .NET Core 7.0 or later.
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.153 | info | PId: 1 | TId: 1] Initializing the Profiler: Reported runtime version : { clrInstanceId: 0, runtimeType:CORE_CLR, majorVersion: 7, minorVersion: 0, buildNumber: 10, qfeVersion: 0 }.
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.153 | info | PId: 1 | TId: 1] No "DD_INTERNAL_OPERATIONAL_METRICS_ENABLED" environment variable has been found. Default: Operational metrics disabled.
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.153 | info | PId: 1 | TId: 1] ProfilerSignalManager::SetupSignalHandler: Successfully setup signal handler for SIGUSR1 signal.
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.153 | info | PId: 1 | TId: 1] ThreadsCpuManager started successfully.
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.154 | info | PId: 1 | TId: 1] ManagedThreadList started successfully.
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.154 | info | PId: 1 | TId: 1] ManagedThreadList started successfully.
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.154 | info | PId: 1 | TId: 1] RuntimeID Store started successfully.
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.154 | info | PId: 1 | TId: 1] WallTimeProvider started successfully.
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.154 | info | PId: 1 | TId: 1] CpuTimeProvider started successfully.
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.154 | info | PId: 1 | TId: 1] ExceptionsProvider started successfully.
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.154 | info | PId: 1 | TId: 1] AllocationsProvider started successfully.
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.154 | info | PId: 1 | TId: 1] ContentionProvider started successfully.
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.154 | info | PId: 1 | TId: 1] Processor cores = 8
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.154 | info | PId: 1 | TId: 1] CPU and wall time sampling period = 9 ms
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.154 | info | PId: 1 | TId: 1] Wall time sampled threads = 5
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.154 | info | PId: 1 | TId: 1] Max CodeHotspots sampled threads = 10
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.154 | info | PId: 1 | TId: 1] Max CPU sampled threads = 64
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.154 | info | PId: 1 | TId: 1] StackSamplerLoopManager started successfully.
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.154 | info | PId: 1 | TId: 1] ApplicationStore started successfully.
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.154 | info | PId: 1 | TId: 1] Starting the samples collector
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.154 | info | PId: 1 | TId: 18] StackSamplerLoopManager::WatcherLoop started.
2023-09-10T03:30:04-03:00   [2023-09-10 06:30:04.154 | info | PId: 1 | TId: 1] SamplesCollector started successfully.
2023-09-10T03:30:05-03:00   [2023-09-10 06:30:05.154 | info | PId: 1 | TId: 18] StackSamplerLoopManager::WatcherLoop finished.
2023-09-10T03:30:06-03:00   [2023-09-10 06:30:06.270 | info | PId: 1 | TId: 38] Processor cores = 8
2023-09-10T03:30:06-03:00   [2023-09-10 06:30:06.270 | info | PId: 1 | TId: 38] CPU and wall time sampling period = 9 ms
2023-09-10T03:30:06-03:00   [2023-09-10 06:30:06.270 | info | PId: 1 | TId: 38] Wall time sampled threads = 5
2023-09-10T03:30:06-03:00   [2023-09-10 06:30:06.270 | info | PId: 1 | TId: 38] Max CodeHotspots sampled threads = 10
2023-09-10T03:30:06-03:00   [2023-09-10 06:30:06.270 | info | PId: 1 | TId: 38] Max CPU sampled threads = 64
2023-09-10T03:30:06-03:00   [2023-09-10 06:30:06.270 | info | PId: 1 | TId: 44] StackSamplerLoopManager::WatcherLoop started.
2023-09-10T03:30:10-03:00   [2023-09-10 06:30:10.035 | info | PId: 1 | TId: 16] PyroscopePprofSink 200
2023-09-10T03:30:20-03:00   [2023-09-10 06:30:20.023 | info | PId: 1 | TId: 16] PyroscopePprofSink 200
2023-09-10T03:30:30-03:00   [2023-09-10 06:30:30.028 | info | PId: 1 | TId: 16] PyroscopePprofSink 200
2023-09-10T03:30:40-03:00   [2023-09-10 06:30:40.020 | info | PId: 1 | TId: 16] PyroscopePprofSink 200
2023-09-10T03:30:50-03:00   [2023-09-10 06:30:50.021 | info | PId: 1 | TId: 16] PyroscopePprofSink 200
2023-09-10T03:31:00-03:00   [2023-09-10 06:31:00.024 | info | PId: 1 | TId: 16] PyroscopePprofSink 200
2023-09-10T03:31:10-03:00   [2023-09-10 06:31:10.029 | info | PId: 1 | TId: 16] PyroscopePprofSink 200
2023-09-10T03:31:20-03:00   [2023-09-10 06:31:20.026 | info | PId: 1 | TId: 16] PyroscopePprofSink 200
2023-09-10T03:31:30-03:00   [2023-09-10 06:31:30.032 | info | PId: 1 | TId: 16] PyroscopePprofSink 200
2023-09-10T03:31:40-03:00   [2023-09-10 06:31:40.029 | info | PId: 1 | TId: 16] PyroscopePprofSink 200
2023-09-10T03:31:50-03:00   [2023-09-10 06:31:50.023 | info | PId: 1 | TId: 16] PyroscopePprofSink 200
korniltsev commented 11 months ago

There is no problem, you can ignore "LoadDynamicLibrary: Error loading dynamic libr" error, this log entry was also removed in the recent commit. Feel free to reopen if the profiler's not working