Filebeat timestamp processor handle timezone abbreviation incorrectly

Hi.

I have log with timestamp in format like this

2020-06-25 19:24:46.676 MSK
2020-06-25 19:24:46.676 MSK
2020-06-25 19:24:46.678 MSK
2020-06-25 19:24:46.712 MSK

My filebeat config (part of it)

filebeat.inputs:
- type: log
  enabled: true
  paths:
    - /var/log/postgresql/postgresql-*-*.csv*
  exclude_files:
    - .gz$
  multiline:
    pattern: '^\d{4}-\d{2}-\d{2} '
    negate: true
    match: after
  processors:
  - add_locale:
      format: abbreviation

  - decode_csv_fields:
      fields:
        message: csv
      separator: ","
      ignore_missing: false
      overwrite_keys: true
      trim_leading_space: false
      fail_on_error: true

  - extract_array:
      field: csv
      omit_empty: false
      overwrite_keys: true
      fail_on_error: true
      mappings:
        postgresql_log_time: 0
        postgresql_user_name: 1
        postgresql_database_name: 2
        postgresql_process_id: 3
        postgresql_connection_from: 4
        postgresql_session_id: 5
        postgresql_session_line_num: 6
        postgresql_command_tag: 7
        postgresql_session_start_time: 8
        postgresql_virtual_transaction_id: 9
        postgresql_transaction_id: 10
        postgresql_error_severity: 11
        postgresql_sql_state_code: 12
        postgresql_sql_message: 13
        postgresql_detail: 14
        postgresql_hint: 15
        postgresql_internal_query: 16
        postgresql_internal_query_pos: 17
        postgresql_context: 18
        postgresql_query: 19
        postgresql_query_pos: 20
        postgresql_location: 21
        postgresql_application_name: 22

  - timestamp:
      field: postgresql_log_time
      layouts:
        - '2006-01-02 15:04:05.999 -07'
        - '2006-01-02 15:04:05.999 -0700'
        - '2006-01-02 15:04:05.999 -07:00'
        - '2006-01-02 15:04:05.999 MST'
      test:
        - '2020-06-22 20:22:28.296 +03'
        - '2020-06-22 20:22:28.296 +0300'
        - '2020-06-22 20:22:28.296 +03:00'
        - '2020-06-22 20:22:28.296 MSK'

  - drop_fields:
      fields:
        - csv

I notice that in Elastic @timestamp stored "as is" (and therefore in Kibana it's displayed like message came three hours from the future) but it's expected that it will be stored in UTC time. After enabling debug logs I found that timezones in numeric formats are parsed correctly.

    2020-06-25T19:24:36.792+0300    DEBUG   [processor.timestamp]   timestamp/timestamp.go:81       Test timestamp [2020-06-22 20:22:28.296 +03] parsed as [2020-06-22 17:22:28.296 +0000 UTC].
    2020-06-25T19:24:36.793+0300    DEBUG   [processor.timestamp]   timestamp/timestamp.go:81       Test timestamp [2020-06-22 20:22:28.296 +0300] parsed as [2020-06-22 17:22:28.296 +0000 UTC].
    2020-06-25T19:24:36.793+0300    DEBUG   [processor.timestamp]   timestamp/timestamp.go:81       Test timestamp [2020-06-22 20:22:28.296 +03:00] parsed as [2020-06-22 17:22:28.296 +0000 UTC].

But this looks like a problem for me

2020-06-25T19:24:36.793+0300    DEBUG   [processor.timestamp]   timestamp/timestamp.go:81       Test timestamp [2020-06-22 20:22:28.296 MSK] parsed as [2020-06-22 20:22:28.296 +0000 UTC].

If timezone present in timestamp as abbreviation filebeat doesn't update time to UTC. Is it a bug or may be it can be fixed by changing layouts?

I expect abbreviations to work because if I use add_locale processor

    processors:
      - add_locale:
          format: abbreviation

event.timezone stored as MSK.

Yes, this might be confusing for users. I assume it processes timestamps correctly, right? I think so, because the event.timezone is present.

If you like you can open an issue in the Beats repo, so the team can decide about the proper presentation.

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.