False "DeadlineExceeded exporting failed, dropping data" errors

[zaharsantarovich]

Describe the bug CloudWatch logs for .NET lambda contain "dropping data" errors for traces, which are sent via the otlp exporter to New Relic. However, all traces are actually successfully sent and are visible in New Relic. Error for the current lambda invocation is logged in several minutes during the next lambda invocation or during the lambda shutdown. Errors are added to CloudWatch logs only for some lambda invocations.

2023-04-03T16:16:53.893+02:00 END RequestId: ea689ecd-3a79-48ac-8103-d0d7ab96f478

2023-04-03T16:16:53.893+02:00 REPORT RequestId: ea689ecd-3a79-48ac-8103-d0d7ab96f478 Duration: 486.32 ms Billed Duration: 487 ms Memory Size: 1024 MB Max Memory Used: 160 MB XRAY TraceId: 1-642adfd5-69df5e643c5b5445190c3bb0 SegmentId: 753af8463ba1df37 Sampled: true

2023-04-03T16:21:53.480+02:00 START RequestId: 77fbe3a6-d2d3-4a5e-aa1a-cd3ef2cb2bad Version: 4

2023-04-03T16:21:53.481+02:00 { "level": "error", "ts": 1680531713.4788353, "caller": "exporterhelper/queued_retry.go:175", "msg": "Exporting failed. No more retries left. Dropping data.", "kind": "exporter", "data_type": "traces", "name": "otlp", "error": "max elapsed time expired rpc error: code = DeadlineExceeded desc = context deadline exceeded", "dropped_items": 8, "stacktrace": "go.opentelemetry.io/collector/exporter/exporterhelper.(*queuedRetrySender).onTemporaryFailure\n\tgo.opentelemetry.io/[email protected]/exporter/exporterhelper/queued_retry.go:175\ngo.opentelemetry.io/collector/exporter/exporterhelper.(*retrySender).send\n\tgo.opentelemetry.io/[email protected]/exporter/exporterhelper/queued_retry.go:410\ngo.opentelemetry.io/collector/exporter/exporterhelper.(*tracesExporterWithObservability).send\n\tgo.opentelemetry.io/[email protected]/exporter/exporterhelper/traces.go:137\ngo.opentelemetry.io/collector/exporter/exporterhelper.(*queuedRetrySender).send\n\tgo.opentelemetry.io/[email protected]/exporter/exporterhelper/queued_retry.go:294\ngo.opentelemetry.io/collector/exporter/exporterhelper.NewTracesExporter.func2\n\tgo.opentelemetry.io/[email protected]/exporter/exporterhelper/traces.go:116\ngo.opentelemetry.io/collector/consumer.ConsumeTracesFunc.ConsumeTraces\n\tgo.opentelemetry.io/collector/[email protected]/traces.go:36\ngo.opentelemetry.io/collector/receiver/otlpreceiver/internal/trace.(*Receiver).Export\n\tgo.opentelemetry.io/collector/receiver/[email protected]/internal/trace/otlp.go:55\ngo.opentelemetry.io/collector/pdata/ptrace/ptraceotlp.rawTracesServer.Export\n\tgo.opentelemetry.io/collector/[email protected]/ptrace/ptraceotlp/grpc.go:88\ngo.opentelemetry.io/collector/pdata/internal/data/protogen/collector/trace/v1._TraceService_Export_Handler.func1\n\tgo.opentelemetry.io/collector/[email protected]/internal/data/protogen/collector/trace/v1/trace_service.pb.go:310\ngo.opentelemetry.io/collector/config/configgrpc.enhanceWithClientInformation.func1\n\tgo.opentelemetry.io/[email protected]/config/configgrpc/configgrpc.go:411\ngoogle.golang.org/grpc.getChainUnaryHandler.func1\n\tgoogle.golang.org/[email protected]/server.go:1163\ngo.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc.UnaryServerInterceptor.func1\n\tgo.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/[email protected]/interceptor.go:349\ngoogle.golang.org/grpc.chainUnaryInterceptors.func1\n\tgoogle.golang.org/[email protected]/server.go:1154\ngo.opentelemetry.io/collector/pdata/internal/data/protogen/collector/trace/v1._TraceService_Export_Handler\n\tgo.opentelemetry.io/collector/[email protected]/internal/data/protogen/collector/trace/v1/trace_service.pb.go:312\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\tgoogle.golang.org/[email protected]/server.go:1336\ngoogle.golang.org/grpc.(*Server).handleStream\n\tgoogle.golang.org/[email protected]/server.go:1704\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.2\n\tgoogle.golang.org/[email protected]/server.go:965" }

2023-04-03T16:21:53.481+02:00 { "level": "error", "ts": 1680531713.4789836, "caller": "exporterhelper/queued_retry.go:296", "msg": "Exporting failed. Dropping data. Try enabling sending_queue to survive temporary failures.", "kind": "exporter", "data_type": "traces", "name": "otlp", "dropped_items": 8, "stacktrace": "go.opentelemetry.io/collector/exporter/exporterhelper.(*queuedRetrySender).send\n\tgo.opentelemetry.io/[email protected]/exporter/exporterhelper/queued_retry.go:296\ngo.opentelemetry.io/collector/exporter/exporterhelper.NewTracesExporter.func2\n\tgo.opentelemetry.io/[email protected]/exporter/exporterhelper/traces.go:116\ngo.opentelemetry.io/collector/consumer.ConsumeTracesFunc.ConsumeTraces\n\tgo.opentelemetry.io/collector/[email protected]/traces.go:36\ngo.opentelemetry.io/collector/receiver/otlpreceiver/internal/trace.(*Receiver).Export\n\tgo.opentelemetry.io/collector/receiver/[email protected]/internal/trace/otlp.go:55\ngo.opentelemetry.io/collector/pdata/ptrace/ptraceotlp.rawTracesServer.Export\n\tgo.opentelemetry.io/collector/[email protected]/ptrace/ptraceotlp/grpc.go:88\ngo.opentelemetry.io/collector/pdata/internal/data/protogen/collector/trace/v1._TraceService_Export_Handler.func1\n\tgo.opentelemetry.io/collector/[email protected]/internal/data/protogen/collector/trace/v1/trace_service.pb.go:310\ngo.opentelemetry.io/collector/config/configgrpc.enhanceWithClientInformation.func1\n\tgo.opentelemetry.io/[email protected]/config/configgrpc/configgrpc.go:411\ngoogle.golang.org/grpc.getChainUnaryHandler.func1\n\tgoogle.golang.org/[email protected]/server.go:1163\ngo.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc.UnaryServerInterceptor.func1\n\tgo.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/[email protected]/interceptor.go:349\ngoogle.golang.org/grpc.chainUnaryInterceptors.func1\n\tgoogle.golang.org/[email protected]/server.go:1154\ngo.opentelemetry.io/collector/pdata/internal/data/protogen/collector/trace/v1._TraceService_Export_Handler\n\tgo.opentelemetry.io/collector/[email protected]/internal/data/protogen/collector/trace/v1/trace_service.pb.go:312\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\tgoogle.golang.org/[email protected]/server.go:1336\ngoogle.golang.org/grpc.(*Server).handleStream\n\tgoogle.golang.org/[email protected]/server.go:1704\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.2\n\tgoogle.golang.org/[email protected]/server.go:965" }

Steps to reproduce Invoke lambda once every several minutes. collector.yaml:

receivers:
  otlp:
    protocols:
      grpc:
        endpoint: localhost:4317
exporters:
  otlp:
    endpoint: ${NEW_RELIC_OPENTELEMETRY_ENDPOINT}
    headers:
      api-key: ${NEW_RELIC_LICENSE_KEY}
service:
  pipelines:
    traces:
      receivers: [otlp]
      exporters: [otlp]

What version of collector/language SDK version did you use? Version: ADOT lambda layer 0-70-0

What language layer did you use? .NET Core 3.1 and .NET 6.

[salper]

cf https://github.com/open-telemetry/opentelemetry-lambda/issues/224#issuecomment-1317754000

(Still got the issue even if I deactivate queueing)