logstash structured logging to support timestamp customization

[maxxedev]

• Add ability to customize logstash timestamp format using LOG_DATEFORMAT_PATTERN property
• and/or, change default logstash timestamp format to match LOG_DATEFORMAT_PATTERN default: yyyy-MM-dd'T'HH:mm:ss.SSSXXX

As is now, logstash timestamp has too much sub-second precision, relative to LOG_DATEFORMAT_PATTERN:

logstash timestamp on Java17+:
2024-11-04T08:55:57.001407539-08:00

LOG_DATEFORMAT_PATTERN:
2024-11-04T09:00:40.584-08:00

logstash doc claims their default is yyyy-MM-dd'T'HH:mm:ss.SSS e.g. 2019-11-03T10:15:30.123+01:00 but I don't think they realize that Java9+ produces greater than 3 digit sub-second precision.

[nosan]

I think you can do this via a custom StructureLoggingJsonMembersCustomizer.

logging.structured.format.console=logstash
logging.structured.json.customizer=task.gh42980.LogstashTimestampCustomizer

package task.gh42980;

import ch.qos.logback.classic.spi.ILoggingEvent;
import org.springframework.boot.json.JsonWriter;
import org.springframework.boot.logging.structured.StructureLoggingJsonMembersCustomizer;

import java.time.OffsetDateTime;
import java.time.format.DateTimeFormatter;
import java.time.temporal.ChronoUnit;

public class LogstashTimestampCustomizer implements StructureLoggingJsonMembersCustomizer<ILoggingEvent> {

	@Override
	public void customize(JsonWriter.Members<ILoggingEvent> members) {
		members.applyingValueProcessor((path, value) -> {
			if ("@timestamp".equals(path.name())) {
				OffsetDateTime time = OffsetDateTime.parse(value.toString(), DateTimeFormatter.ISO_OFFSET_DATE_TIME);
				return DateTimeFormatter.ISO_OFFSET_DATE_TIME.format(time.truncatedTo(ChronoUnit.SECONDS));
			}
			return value;
		});
	}
}

{"@timestamp":"2024-11-04T11:19:06+02:00","@version":"1","message":"Starting service [Tomcat]","logger_name":"org.apache.catalina.core.StandardService","thread_name":"main","level":"INFO","level_value":20000}

[nosan]

IMO, it would be convenient to have something like this additionally to ValueProcessor

public class LogstashTimestampCustomizer implements StructureLoggingJsonMembersCustomizer<ILoggingEvent> {

	@Override
	public void customize(JsonWriter.Members<ILoggingEvent> members) {
		members.addOrReplace("@timestamp", (event) -> event.getInstant().truncatedTo(ChronoUnit.SECONDS));
	}

}

[mhalbritter]

As is now, logstash timestamp has too much sub-second precision.

"Too much" for you personally or did you find a specification we violate?

@philwebb : WDYT about #42980 (comment)?

[maxxedev]

#42980 (comment) I think you can do this via a custom StructureLoggingJsonMembersCustomizer.

Yes, but I think this should be configurable through properties.
 

#42980 (comment) "Too much" for you personally or did you find a specification we violate?

relative to default spring-boot console output. original comment updated

[philwebb]

With regards to addOrReplace, it doesn't look like we have a great system in place currently to deal with repeat calls to add if the same name is used. Things are a little complicated because a single Member can contribute multiple pairs (and hence multiple names). I wonder if JsonValueWriter should at least guard against the same name being written twice? I don't think we should rush to add a new addOrReplace method just yet.

For the customizer, you can use the whenHasPath helper which helps a bit, but it's still verbose:

public class LogstashTimestampCustomizer implements StructureLoggingJsonMembersCustomizer<ILoggingEvent> {

	private static final DateTimeFormatter formatter = DateTimeFormatter.ISO_OFFSET_DATE_TIME;

	@Override
	public void customize(JsonWriter.Members<ILoggingEvent> members) {
		members.applyingValueProcessor(ValueProcessor.of(this::truncate).whenHasPath("@timestamp"));

	}

	private String truncate(String value) {
		OffsetDateTime time = OffsetDateTime.parse(value, formatter);
		return formatter.format(time.truncatedTo(ChronoUnit.SECONDS));
	}

}

[mhalbritter]

CONSOLE_LOG_PATTERN and LOG_DATEFORMAT_PATTERN only take effect when using plaintext console logging. Some log formats have fixed date formats (e.g. ecs is always in UTC) and if LOG_DATEFORMAT_PATTERN would influence the structured logging dateformat, this would break some of the formats.

There's a workaround if you really want to change the timestamp format.

Given that the default config of https://github.com/logfellow/logstash-logback-encoder also uses a non-truncated date format, I don't think we should do anything here.