Skip to content

[bug] Exporting logs with OtlpExporter and grpc not working. #6143

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

Open
pravinpushkar opened this issue Feb 19, 2025 · 21 comments
Open

[bug] Exporting logs with OtlpExporter and grpc not working. #6143

pravinpushkar opened this issue Feb 19, 2025 · 21 comments
Assignees
Labels
bug Something isn't working needs-triage New issues which have not been classified or triaged by a community member pkg:OpenTelemetry.Exporter.OpenTelemetryProtocol Issues related to OpenTelemetry.Exporter.OpenTelemetryProtocol NuGet package

Comments

@pravinpushkar
Copy link

Package

OpenTelemetry

Package Version

Package Name Version
OpenTelemetry.Api 1.11.1
OpenTelemetry 1.11.1
TBD TBD

Runtime Version

8

Description

This seems still reproducible with 1.11.1.

Related issue - #6067
#6083

Steps to Reproduce

Here is samle code -

string loggingendpoint = Environment.GetEnvironmentVariable("LOGGING_GRPC_ENDPOINT") ?? "localhost";

if (string.IsNullOrEmpty(loggingendpoint))
{
    Console.WriteLine("No logging endpoint provided.");
}
AppContext.SetSwitch("System.Net.Http.SocketsHttpHandler.Http2UnencryptedSupport", true);

Console.WriteLine($"Logging endpoint: {loggingendpoint}");
using var loggerFactory = LoggerFactory.Create(builder =>
{
    builder.AddOpenTelemetry(options =>
    {
        options.IncludeScopes = true;
        options.IncludeFormattedMessage = true;
        options.AddConsoleExporter();
        options.AddOtlpExporter((exOpt, pOpts) =>
        {
            exOpt.Endpoint = new Uri($"http://{loggingendpoint}");
            exOpt.Protocol = OtlpExportProtocol.Grpc;
        });
    });
});

var logger = loggerFactory.CreateLogger("Log");

using (logger.BeginScope(new List<KeyValuePair<string, object>>{
                    new KeyValuePair<string, object>("category", "OTLPLOGExporter"),
                }))
{
    logger.LogInformationWithDetails($"LOGGING_GRPC_ENDPOINT {loggingendpoint}");

    logger.LogInformationWithDetails("All Done!");
    // to flush the in-memory buffer and ensure all logs are exported.

    loggerFactory.Dispose();
}

Expected Result

Logs successfully exported

Actual Result

Logs not able to get exported. No errors.

Additional Context

No response

@pravinpushkar pravinpushkar added bug Something isn't working needs-triage New issues which have not been classified or triaged by a community member labels Feb 19, 2025
@github-actions github-actions bot added the pkg:OpenTelemetry Issues related to OpenTelemetry NuGet package label Feb 19, 2025
@Kielek
Copy link
Contributor

Kielek commented Feb 19, 2025

To make it your example working I need to change LogInformationWithDetails to LogInformation and I changed localhost to localhost:4317.

Results (same for .NET8 and .NET9):

splunk-collector-1  | 2025-02-19T11:38:16.318Z  info    ResourceLog #0
splunk-collector-1  | Resource SchemaURL:
splunk-collector-1  | Resource attributes:
splunk-collector-1  |      -> telemetry.sdk.name: Str(opentelemetry)
splunk-collector-1  |      -> telemetry.sdk.language: Str(dotnet)
splunk-collector-1  |      -> telemetry.sdk.version: Str(1.11.1)
splunk-collector-1  |      -> service.name: Str(unknown_service:dotnet-6142)
splunk-collector-1  | ScopeLogs #0
splunk-collector-1  | ScopeLogs SchemaURL:
splunk-collector-1  | InstrumentationScope Log
splunk-collector-1  | LogRecord #0
splunk-collector-1  | ObservedTimestamp: 2025-02-19 11:38:16.1039371 +0000 UTC
splunk-collector-1  | Timestamp: 2025-02-19 11:38:16.1039371 +0000 UTC
splunk-collector-1  | SeverityText: Information
splunk-collector-1  | SeverityNumber: Info(9)
splunk-collector-1  | Body: Str(LOGGING_GRPC_ENDPOINT localhost:4317)
splunk-collector-1  | Attributes:
splunk-collector-1  |      -> {OriginalFormat}: Str(LOGGING_GRPC_ENDPOINT localhost:4317)
splunk-collector-1  |      -> category: Str(OTLPLOGExporter)
splunk-collector-1  | Trace ID:
splunk-collector-1  | Span ID:
splunk-collector-1  | Flags: 0
splunk-collector-1  | LogRecord #1
splunk-collector-1  | ObservedTimestamp: 2025-02-19 11:38:16.1244879 +0000 UTC
splunk-collector-1  | Timestamp: 2025-02-19 11:38:16.1244879 +0000 UTC
splunk-collector-1  | SeverityText: Information
splunk-collector-1  | SeverityNumber: Info(9)
splunk-collector-1  | Body: Str(All Done!)
splunk-collector-1  | Attributes:
splunk-collector-1  |      -> {OriginalFormat}: Str(All Done!)
splunk-collector-1  |      -> category: Str(OTLPLOGExporter)
splunk-collector-1  | Trace ID:
splunk-collector-1  | Span ID:
splunk-collector-1  | Flags: 0
splunk-collector-1  |   {"kind": "exporter", "data_type": "logs", "name": "debug/debug"}

Could you please prepare more detailed steps to reproduce? docker compose file could be beneficial to reproduce it.

@pravinpushkar
Copy link
Author

@Kielek Thanks a lot for responding quickly.

I need to change LogInformationWithDetails to LogInformation and I changed localhost to localhost:4317.

Sorry, These are my local setup method and need to change it accordingly. The output above shows from console exporter, which work fine for me as well with docker a image. These logs are not actually reaching the grpc receiver.

The same code when I use it with 1.10.0 open telemetry SDK, it works fine and logs are reaching the grpc receiver.

@Kielek
Copy link
Contributor

Kielek commented Feb 19, 2025

It is debug log from the collector with grpc receiver

@pravinpushkar
Copy link
Author

ok, it it a bit strange that this code works with 1.10.0 but not with 1.11.1.

@Kielek
Copy link
Contributor

Kielek commented Feb 21, 2025

As you see, it is working with 1.11.1 for me. Can you share Minimal, Reproducible Example?

@rajkumar-rangaraj
Copy link
Contributor

@pravinpushkar This could be related to #6138. Can you validate this?

@jlaherran
Copy link

@pravinpushkar did you check you are running .NET8 and not .NET6? I had the same issue and it was regarding .NET6..

@martinjt
Copy link
Member

martinjt commented Mar 3, 2025

Can you check how you're ending the application? The OTLP exporter runs on a batch interval, so if you end your application too soon, then it may cause an issue that you're finishing before it's exported.

Also check out the self diagnostics to see if there's a failure connecting to your backend.

https://github.com/open-telemetry/opentelemetry-dotnet/blob/main/src/OpenTelemetry/README.md#self-diagnostics

@jlaherran
Copy link

jlaherran commented Mar 3, 2025

I'm getting these exceptions using .NET6
Request to http://localhost:4317/opentelemetry.proto.collector.logs.v1.LogsService/Export failed, the response ended prematurely.
Just targeting to .NET8 it works as expected.

2025-03-03T21:49:11.7761154Z:HTTP request to {0} failed. Exception: {1}{http://localhost:4317/opentelemetry.proto.collector.logs.v1.LogsService/Export}{System.Net.Http.HttpRequestException: An error occurred while sending the request.
---> System.IO.IOException: The response ended prematurely.
at System.Net.Http.HttpConnection.FillAsync(Boolean async)
at System.Net.Http.HttpConnection.ReadNextResponseHeaderLineAsync(Boolean async, Boolean foldedHeadersAllowed)
at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
--- End of inner exception stack trace ---
at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
at System.Net.Http.HttpClient.g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
at OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation.ExportClient.OtlpGrpcExportClient.SendExportRequest(Byte[] buffer, Int32 contentLength, DateTime deadlineUtc, CancellationToken cancellationToken)}
2025-03-03T21:49:16.4035498Z:HTTP request to {0} failed. Exception: {1}{http://localhost:4317/opentelemetry.proto.collector.trace.v1.TraceService/Export}{System.Net.Http.HttpRequestException: An error occurred while sending the request.
---> System.IO.IOException: The response ended prematurely.
at System.Net.Http.HttpConnection.FillAsync(Boolean async)
at System.Net.Http.HttpConnection.ReadNextResponseHeaderLineAsync(Boolean async, Boolean foldedHeadersAllowed)
at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
--- End of inner exception stack trace ---
at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
at System.Net.Http.HttpClient.g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
at OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation.ExportClient.OtlpGrpcExportClient.SendExportRequest(Byte[] buffer, Int32 contentLength, DateTime deadlineUtc, CancellationToken cancellationToken)}
2025-03-03T21:49:17.1738538Z:HTTP request to {0} failed. Exception: {1}{http://localhost:4317/opentelemetry.proto.collector.logs.v1.LogsService/Export}{System.Net.Http.HttpRequestException: An error occurred while sending the request.
---> System.IO.IOException: The response ended prematurely.
at System.Net.Http.HttpConnection.FillAsync(Boolean async)
at System.Net.Http.HttpConnection.ReadNextResponseHeaderLineAsync(Boolean async, Boolean foldedHeadersAllowed)
at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
--- End of inner exception stack trace ---
at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
at System.Net.Http.HttpClient.g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
at OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation.ExportClient.OtlpGrpcExportClient.SendExportRequest(Byte[] buffer, Int32 contentLength, DateTime deadlineUtc, CancellationToken cancellationToken)}

@rajkumar-rangaraj
Copy link
Contributor

@pravinpushkar Could you please try with the latest version 1.11.2 and check if it works now?

@stalek71
Copy link

stalek71 commented Mar 19, 2025

It doesn't work with 1.11.2 as well (tested using .Net 9 runtime).

Exporting works (and is visible, e.g., in Aspire Dashboard) when you use the web stack, meaning when you start building the stack using WebApplication.CreateBuilder(args).

It does not work when you try to build the stack manually, starting the definition with Host.CreateDefaultBuilder(args) or manually creating the Logger configuration, as is the case described in this ticket.

@stalek71
Copy link

stalek71 commented Mar 19, 2025

Minimal example:

using System.Diagnostics;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Hosting;
using Microsoft.Extensions.Logging;
using OpenTelemetry;
using OpenTelemetry.Logs;
using OpenTelemetry.Resources;
using OpenTelemetry.Trace;

namespace OtelTests;

class Program
{
    static void Main(string[] args)
    {
        IHost host = Host.CreateDefaultBuilder(args)
            .ConfigureServices(services =>
            {
                services.AddOpenTelemetry()
                .ConfigureResource(builder => builder.AddService("as-app"))
                .WithLogging(loggingBuilder =>
                {
                    //loggingBuilder
                    //.AddConsoleExporter()
                    //.AddOtlpExporter(); // Default endpoint is http://localhost:4317
                })
                .UseOtlpExporter();
            })
            .Build();

        ILogger<Program> logger = host.Services.GetRequiredService<ILogger<Program>>();

        for (int logIndex = 0; logIndex < 10; logIndex++)
        {
            logger.LogInformation("This is log entry nr {NR}", logIndex);
        }
        
        host.Run();
    }
}

Project def (used libs/nugets/deps):

<Project Sdk="Microsoft.NET.Sdk">

  <PropertyGroup>
    <OutputType>Exe</OutputType>
    <TargetFramework>net9.0</TargetFramework>
    <ImplicitUsings>enable</ImplicitUsings>
    <Nullable>enable</Nullable>
  </PropertyGroup>

  <ItemGroup>
    <PackageReference Include="Microsoft.Extensions.DependencyInjection" Version="9.0.3" />
    <PackageReference Include="Microsoft.Extensions.Hosting" Version="9.0.3" />
    <PackageReference Include="Microsoft.Extensions.Logging" Version="9.0.3" />
    <PackageReference Include="OpenTelemetry" Version="1.11.2" />
    <PackageReference Include="OpenTelemetry.Exporter.Console" Version="1.11.2" />
    <PackageReference Include="OpenTelemetry.Exporter.OpenTelemetryProtocol" Version="1.11.2" />
    <PackageReference Include="OpenTelemetry.Extensions.Hosting" Version="1.11.2" />
  </ItemGroup>

</Project>

The command to run Aspire Dashboard:

docker run -it -p 18888:18888 -p 4317:18889 -p 4318:18890 -e Dashboard__ResourceServiceClient__AuthMode=Unsecured -e DOTNET_DASHBOARD_UNSECURED_ALLOW_ANONYMOUS=true -e DASHBOARD__OTLP__CORS__ALLOWEDORIGINS='*' -d --name aspire-dashboard mcr.microsoft.com/dotnet/aspire-dashboard:latest

The Dashboard is available here:
http://localhost:18888/structuredlogs

Console screenshot:

Image

Aspire log screenshot

Image

@stalek71
Copy link

stalek71 commented Apr 1, 2025

??

@martinjt
Copy link
Member

martinjt commented Apr 1, 2025

You need to call a flush on the tracerprovider to cause the batch to be sent.

@stalek71
Copy link

stalek71 commented Apr 1, 2025

Still nothing. Maybe I'm just doing something wrong?
From my point of view, after launching OTEL, flush operation should work automatically (especially upon application shutdown)

class Program
{
    static void Main(string[] args)
    {
        IHost host = Host.CreateDefaultBuilder(args)
            .ConfigureServices(services =>
            {
                services.AddOpenTelemetry()
                .ConfigureResource(builder => builder.AddService("as-app"))
                .WithLogging(loggingBuilder =>
                {
                    //loggingBuilder
                    //.AddConsoleExporter()
                    //.AddOtlpExporter(); // Defaukt endpoint is http://localhost:4317
                })
                .UseOtlpExporter();
            })
            .Build();

        ILogger<Program> logger = host.Services.GetRequiredService<ILogger<Program>>();

        for (int logIndex = 0; logIndex < 10; logIndex++)
        {
            logger.LogInformation("This is log entry nr {NR}", logIndex);
        }

        var tracerProvider = host.Services.GetRequiredService<TracerProvider>();
        tracerProvider.ForceFlush();

        host.Run();
    }
}

@martinjt
Copy link
Member

martinjt commented Apr 1, 2025

Do you have the logging level set to include information? Maybe try logging an error?

@stalek71
Copy link

stalek71 commented Apr 1, 2025

I have the default settings, so as far as I remember, it's the Information level.
I also checked the Error level, of course, but it didn’t change anything

@rajkumar-rangaraj
Copy link
Contributor

Note that host.Run(); is the point where the OpenTelemetry providers are built. Any logs, spans, or metrics emitted before this line will not be captured.

You can refer to this demo app in the Azure SDK repo for guidance:
Azure.Monitor.OpenTelemetry.LiveMetrics.Demo/Program.cs#L36

@TimothyMothra TimothyMothra added pkg:OpenTelemetry.Exporter.OpenTelemetryProtocol Issues related to OpenTelemetry.Exporter.OpenTelemetryProtocol NuGet package and removed pkg:OpenTelemetry Issues related to OpenTelemetry NuGet package labels Apr 1, 2025
@stalek71
Copy link

This code doesn't work as well of course...

using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Hosting;
using Microsoft.Extensions.Logging;
using OpenTelemetry;
using OpenTelemetry.Logs;
using OpenTelemetry.Resources;
using OpenTelemetry.Trace;

namespace OtelTests;

public class SomeHostedService : IHostedService
{
    private readonly ILogger<SomeHostedService> _logger;
    private readonly TracerProvider _tracerProvider;
    public SomeHostedService(ILogger<SomeHostedService> logger, TracerProvider tracerProvider)
    {
        _logger = logger;
        _tracerProvider = tracerProvider;
    }
    public Task StartAsync(CancellationToken cancellationToken)
    {
        _logger.LogInformation("Hosted service started.");
        return Task.CompletedTask;
    }
    public Task StopAsync(CancellationToken cancellationToken)
    {
        _logger.LogInformation("Hosted service stopped.");
        return Task.CompletedTask;
    }
}

class Program
{
    static void Main(string[] args)
    {
        IHost host = Host.CreateDefaultBuilder(args)
            .ConfigureServices(services =>
            {
                services.AddOpenTelemetry()
                .ConfigureResource(builder => builder.AddService("as-app"))
                .WithLogging(loggingBuilder =>
                {
                    //loggingBuilder
                    //.AddConsoleExporter()
                    //.AddOtlpExporter(); // Defaukt endpoint is http://localhost:4317
                })
                .UseOtlpExporter();

               services.AddSingleton<IHostedService, SomeHostedService>();

            })
            .Build();

        ILogger<Program> logger = host.Services.GetRequiredService<ILogger<Program>>();

        for (int logIndex = 0; logIndex < 10; logIndex++)
        {
            logger.LogError("This is log entry nr {NR}", logIndex);
        }

        var tracerProvider = host.Services.GetRequiredService<TracerProvider>();
        tracerProvider.ForceFlush();

        host.Run();
    }
}

Image

@stalek71
Copy link

It looks like this was my mistake (or rather an issue with my computer). When I start the Docker image and run the test program, it tries to establish a connection over IPv6, but for some reason, the Docker image doesn’t map that protocol and only allows connections over IPv4.

That is, when I use localhost as the endpoint address, the connection is attempted via IPv6.
However, when I use 127.0.0.1, the program connects to Aspire and I can see entries in the logs.

I still need to investigate why this is happening, because I haven’t blocked IPv6 in Docker Desktop, and explicitly enabling it in the config followed by a restart doesn’t help — communication over IPv6 still doesn’t work.

@stalek71
Copy link

I just found such info:
IPv6 is only supported on Docker daemons running on Linux hosts.

https://docs.docker.com/engine/daemon/ipv6/

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working needs-triage New issues which have not been classified or triaged by a community member pkg:OpenTelemetry.Exporter.OpenTelemetryProtocol Issues related to OpenTelemetry.Exporter.OpenTelemetryProtocol NuGet package
Projects
None yet
Development

No branches or pull requests

7 participants