Skip to content

Inconsistent and unexpected behavior of timestampPattern/timeZone settings #1012

@DavidSonoda

Description

@DavidSonoda

Describe the bug

When setting timestampPattern in different custom patterns (not predefined), most of the time they are not respected. While doing that, sometimes the timeZone setting is applied, other times it is not.

To Reproduce

Steps to reproduce the behavior:

My logback-spring.xml looks like this,

<springProfile name="dev">
        <appender name="logstashLogAppender" class="net.logstash.logback.appender.LogstashTcpSocketAppender">
            <destination>${logstashHost}:${logstashPort}</destination>
            <keepAliveDuration>10 seconds</keepAliveDuration>
            <includeCallerData>true</includeCallerData>
            <encoder class="net.logstash.logback.encoder.LogstashEncoder">
                <includeContext>false</includeContext>
                <includeCallerData>true</includeCallerData>
                
                <!-- In following discussion, only the below 2 settings are modified-->
                <timestampPattern>yyyy-MM-dd'T'HH:mm:ss.SSSZZZZ</timestampPattern>
                <timeZone>GMT+8</timeZone>

                <customFields>
                    {
                        "project":"${logstashProjectName}",
                        "app":"${logstashAppName}",
                        "commit":"${COMMIT_ID}",
                        "spring_profile":"${activeProfile}"
                    }
                </customFields>
            </encoder>
        </appender>
    </springProfile>

Several cases that I have tested,

Case 1

                <timestampPattern>yyyy-MM-dd'T'HH:mm:ss.SSSZZZZ</timestampPattern>
                <timeZone>GMT+8</timeZone>

Expected output
"@timestamp":"2024-03-20T18:04:09.148GMT+08:00" (GMT+8, the full form of localized offset)

Actual output
"@timestamp":"2024-03-20T10:04:09.148Z" (UTC, missing the full form of localized offset)

Case 2

                <timestampPattern>yyyy-MM-dd'T'HH:mm:ss.SSS</timestampPattern>
                <timeZone>GMT+8</timeZone>

Expected output
"@timestamp":"2024-03-20T18:04:09.148" (GMT+8, no zone offset)

Actual output
"@timestamp":"2024-03-20T10:04:09.148Z" (UTC, and the trailing 'Z')

Case 3

                <timestampPattern>yyyy-MM-dd HH:mm:ss.SSSZZZZ</timestampPattern>
                <timeZone>GMT+8</timeZone>

Expected output
"@timestamp":"2024-03-20 18:34:15.976GMT+08:00" (GMT+8, full form of zone offset)

Actual output
Now things get a bit more interesting, there's a new field added with a preceding underscore, which is _@timestamp. And it's respecting both the pattern and the time zone. However, the time zone and the format of OG field @timestamp are both incorrect, as shown below. And there's even a bit discrepancy between this 2 fields in terms of their actual instant.
"_@timestamp":"2024-03-20 18:34:15.976GMT+08:00","@timestamp":"2024-03-20T10:33:08.907377169Z"

Expected behavior

Both settings should be applied, without adding extra field. Even if adding extra field is inevitable, discrepancy between the actual instant value of these 2 fields should be 0.

Cases are discussed above.

Additional context

Build tools: maven
Spring Boot version: 3.2.3
kotlin version: 1.9.22

  • logstash-logback-encoder 7.4
  • logback version 1.4.14
  • jackson version: com.fasterxml.jackson.module:jackson-module-kotlin:2.15.4
  • java version: 21.0.1

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions