Azure Functions logs dropped due to timestamp parsing error

[eberkut]

Component(s)

pkg/translator/azure, pkg/translator/azurelogs

What happened?

Description

For Azure Functions, all logs are being dropped by the OpenTelemetry collector due to a timestamp parsing error. The issue is that the timestamp format used in the logs (11/20/2024 13:57:18) is not being correctly parsed by the OpenTelemetry collector. The collector expects an ISO8601 or RFC3339 format for timestamps, which leads to the logs being dropped.

Checking in Azure documentation, we cannot find a definitive answer regarding the proper format for timestamps in Azure logs:
https://learn.microsoft.com/en-us/azure/azure-monitor/essentials/resource-logs-schema#top-level-common-schema
https://learn.microsoft.com/en-us/azure/azure-monitor/essentials/activity-log-schema#schema-from-storage-account-and-event-hubs
https://learn.microsoft.com/en-us/azure/azure-monitor/reference/tables/functionapplogs

However, Microsoft support has confirmed the timestamp format logged by Azure Functions varies depending on the App Service Plan being used:

• Linux Elastic Premium: Date-time in US format
• Linux Dedicated: Date-time in US format
• Linux Consumption: Date-time in ISO 8601 format
• Windows Elastic Premium: Date-time in ISO 8601 format
• Windows Dedicated: Date-time in ISO 8601 format
• Windows Consumption: Date-time in ISO 8601 format

See Azure/azure-functions-host#7864. No ETA has been provided for Functions Runtime v5 which would supposedly fix the issue.

A similar issue has been previously reported in:
#31244
#27589

Steps to Reproduce

1. Configure an Azure Function with a Linux Elastic Premium or Linux Dedicated App Service Plan.
2. Set up the service's diagnostic settings to forward logs to an Azure Event Hub.
3. Configure an OpenTelemetry Collector with a receiver for Azure Event Hub.
4. Send a log event with a timestamp in the US format (MM/DD/YYYY HH:MM:SS).

Expected Result

Logs from Azure Functions should be processed without errors, regardless of the timestamp format used.

Actual Result

An error is generated when processing logs with a timestamp in US format, leading to logs being dropped.

Collector version

0.114.0

Environment information

OS: "Ubuntu 20.04"

OpenTelemetry Collector configuration

receivers:
  azureeventhub:
    connection: <REDACTED>
    format: azure
  otlp:
    protocols:
      http:
        endpoint: 0.0.0.0:4318
      grpc:
        endpoint: 0.0.0.0:4317

processors:
  batch: {}

exporters:
  otlphttp:
    endpoint: <scrubbed_endpoint>
    headers:
      Authorization: "<REDACTED>"

service:
  pipelines:
    logs:
      receivers: [azureeventhub]
      processors: [batch]
      exporters: [otlphttp]
  telemetry:
    logs:
      level: "DEBUG"
      encoding: "json"
    metrics:
      level: normal
      address: 0.0.0.0:8888
  extensions: [health_check]

Log output

{'level':'warn','ts':1732127778.2994077,'caller':'azure@v0.111.0/resourcelogs_to_logs.go:112','msg':'Unable to convert timestamp from log','exporter_id':'aci-93f27a-ci-aitechsbx-dit-01','kind':'receiver','name':'azureeventhub','data_type':'logs','timestamp':'11/20/2024 03:39:19'}

Additional context

Sample events retrieved directly from Azure Event Hub:

{
  "records": [
    {
      "level": "Informational",
      "resourceId": "/SUBSCRIPTIONS/REDACTED/RESOURCEGROUPS/REDACTED/PROVIDERS/MICROSOFT.WEB/SITES/REDACTED",
      "category": "FunctionAppLogs",
      "location": "REDACTED",
      "operationName": "Microsoft.Web/sites/functions/log",
      "time": "11/20/2024 13:57:18",
      "properties": "{'appName':'REDACTED','roleInstance':'REDACTED','message':'Executing Functions.http_app_func (Reason=This function was programmatically called via the host APIs., Id=REDACTED)','category':'Function.http_app_func','hostVersion':'4.1036.2.2','functionInvocationId':'REDACTED','functionName':'Functions.http_app_func','hostInstanceId':'REDACTED','level':'Information','levelId':2,'processId':944,'eventId':1,'eventName':'FunctionStarted'}",
      "EventStampType": "Stamp",
      "EventPrimaryStampName": "REDACTED",
      "EventStampName": "REDACTED",
      "Host": "REDACTED",
      "EventIpAddress": "REDACTED"
    },
    {
      "level": "Informational",
      "resourceId": "/SUBSCRIPTIONS/REDACTED/RESOURCEGROUPS/REDACTED/PROVIDERS/MICROSOFT.WEB/SITES/REDACTED",
      "category": "FunctionAppLogs",
      "location": "REDACTED",
      "operationName": "Microsoft.Web/sites/functions/log",
      "time": "11/20/2024 13:57:18",
      "properties": "{'appName':'REDACTED','roleInstance':'REDACTED','message':'Executed Functions.http_app_func (Succeeded, Id=REDACTED, Duration=19ms)','category':'Function.http_app_func','hostVersion':'4.1036.2.2','functionInvocationId':'REDACTED','functionName':'Functions.http_app_func','hostInstanceId':'REDACTED','level':'Information','levelId':2,'processId':944,'eventId':2,'eventName':'FunctionCompleted'}",
      "EventStampType": "Stamp",
      "EventPrimaryStampName": "REDACTED",
      "EventStampName": "REDACTED",
      "Host": "REDACTED",
      "EventIpAddress": "REDACTED"
    }
  ]
}

[github-actions]

Pinging code owners:

• pkg/translator/azure: @open-telemetry/collector-approvers @atoulme @cparkins
• pkg/translator/azurelogs: @atoulme @cparkins @MikeGoldsmith

See Adding Labels via Comments if you do not have permissions to add labels yourself.

[braydonk]

Triage: The issue appears to be well specified and has all necessary information. Setting to waiting on codeowners.

[hgaol]

The current azure event hub receiver can only parse iso8601 time string. I think it can support customized time format for more use cases as well as to address this issue. The newly added configs might be similar as below.

receivers
  azureeventhub:
    connection: "xxxxx"
    format: "azure"
    # optional
    time_format:
      # All supported time format. Default is empty string array, which means using the current iso8601 parser. The format is based on https://pkg.go.dev/time#Layout. If no time-zone info, will use UTC time.
      logs: ["01/02/2006 15:04:05","2006-01-02 15:04:05","2006-01-02T15:04:05Z07:00"]
      metrics: [""]
      traces: [""]
    # optional
    time_offset:
      # The offset hours to parsed time. Mainly for cases when there's no time-zone info in time string. default is 0.
      logs: -8
      metrics: +8
      traces: -8

pls let me know if any comments on this proposal. If no objections, I'd like to implement it.

[eberkut]

@hgaol Since Microsoft confirmed the specific time format for this issue, adding support for auto-detection of this format makes sense. However, making the timestamp formats configurable would be a more flexible and future-proof solution. This approach would allow handling any unforeseen changes in timestamp formats without needing further code modifications.