opendev/gerrit
Code Issues Proposed changes

Use ISO 8601 timestamp format for error/httpd/sshd logs

Browse Source 
The error-, httpd- and sshd logs in text and json format were not using
a consistent timestamp format. This was confusing, especially since not
all logs would show the timezone, and was creating overhead work to
configure log parsers.

Now the ISO 8601 format is used for all logs. The format looks like this:
"yyyy-MM-dd'T'HH:mm:ss,SSSZ" (e.g. "2020-02-27T17:35:12,784+0100").
Using a standardized format should make it easier to read and parse the
timestamp and avoid confusion.

Change-Id: I365109d33e77df4d780dcff7f5e8bcb79b0bb300
This commit is contained in:
Thomas Draebing
2020-02-27 17:36:39 +01:00
parent 8ba0926df1
commit 31037d324d
8 changed files with 68 additions and 118 deletions
Download Patch File Download Diff File Expand all files Collapse all files

8
java/com/google/gerrit/pgm/http/jetty/HttpLogJsonLayout.java
View File

@@ -26,16 +26,10 @@ import static com.google.gerrit.pgm.http.jetty.HttpLog.P_USER_AGENT;
import com.google.gerrit.util.logging.JsonLayout;
import com.google.gerrit.util.logging.JsonLogEntry;
import java.time.format.DateTimeFormatter;
import org.apache.log4j.spi.LoggingEvent;
public class HttpLogJsonLayout extends JsonLayout {
@Override
public DateTimeFormatter createDateTimeFormatter() {
return DateTimeFormatter.ofPattern("dd/MMM/yyyy:HH:mm:ss,SSS Z");
}
@Override
public JsonLogEntry toJsonLogEntry(LoggingEvent event) {
return new HttpJsonLogEntry(event);
@@ -59,7 +53,7 @@ public class HttpLogJsonLayout extends JsonLayout {
this.host = getMdcString(event, P_HOST);
this.thread = event.getThreadName();
this.user = getMdcString(event, P_USER);
this.timestamp = formatDate(event.getTimeStamp());
this.timestamp = timestampFormatter.format(event.getTimeStamp());
this.method = getMdcString(event, P_METHOD);
this.resource = getMdcString(event, P_RESOURCE);
this.protocol = getMdcString(event, P_PROTOCOL);

30
java/com/google/gerrit/pgm/http/jetty/HttpLogLayout.java
View File

@@ -14,24 +14,15 @@
package com.google.gerrit.pgm.http.jetty;
import java.text.SimpleDateFormat;
import java.util.Date;
import java.util.TimeZone;
import com.google.gerrit.util.logging.LogTimestampFormatter;
import org.apache.log4j.Layout;
import org.apache.log4j.spi.LoggingEvent;
public final class HttpLogLayout extends Layout {
private final SimpleDateFormat dateFormat;
private long lastTimeMillis;
private String lastTimeString;
private final LogTimestampFormatter timestampFormatter;
public HttpLogLayout() {
final TimeZone tz = TimeZone.getDefault();
dateFormat = new SimpleDateFormat("dd/MMM/yyyy:HH:mm:ss Z");
dateFormat.setTimeZone(tz);
lastTimeMillis = System.currentTimeMillis();
lastTimeString = dateFormat.format(new Date(lastTimeMillis));
timestampFormatter = new LogTimestampFormatter();
}
@Override
@@ -53,7 +44,7 @@ public final class HttpLogLayout extends Layout {
buf.append(' ');
buf.append('[');
formatDate(event.getTimeStamp(), buf);
buf.append(timestampFormatter.format(event.getTimeStamp()));
buf.append(']');
buf.append(' ');
@@ -104,19 +95,6 @@ public final class HttpLogLayout extends Layout {
}
}
private void formatDate(long now, StringBuilder sbuf) {
final long rounded = now - (int) (now % 1000);
if (rounded != lastTimeMillis) {
synchronized (dateFormat) {
lastTimeMillis = rounded;
lastTimeString = dateFormat.format(new Date(lastTimeMillis));
sbuf.append(lastTimeString);
}
} else {
sbuf.append(lastTimeString);
}
}
@Override
public boolean ignoresThrowable() {
return true;

7
java/com/google/gerrit/pgm/util/ErrorLogFile.java
View File

@@ -18,6 +18,7 @@ import com.google.gerrit.common.FileUtil;
import com.google.gerrit.extensions.events.LifecycleListener;
import com.google.gerrit.server.config.SitePaths;
import com.google.gerrit.server.util.SystemLog;
import com.google.gerrit.util.logging.LogTimestampFormatter;
import java.io.IOException;
import java.nio.file.Path;
import org.apache.log4j.ConsoleAppender;
@@ -77,7 +78,11 @@ public class ErrorLogFile {
if (text) {
root.addAppender(
SystemLog.createAppender(
logdir, LOG_NAME, new PatternLayout("[%d] [%t] %-5p %c %x: %m%n"), rotate));
logdir,
LOG_NAME,
new PatternLayout(
"[%d{" + LogTimestampFormatter.TIMESTAMP_FORMAT + "}] [%t] %-5p %c %x: %m%n"),
rotate));
}
if (json) {

8
java/com/google/gerrit/pgm/util/ErrorLogJsonLayout.java
View File

@@ -19,7 +19,6 @@ import com.google.gerrit.util.logging.JsonLogEntry;
import com.google.gson.annotations.SerializedName;
import java.net.InetAddress;
import java.net.UnknownHostException;
import java.time.format.DateTimeFormatter;
import java.util.HashMap;
import java.util.Map;
import org.apache.log4j.spi.LoggingEvent;
@@ -28,11 +27,6 @@ import org.apache.log4j.spi.ThrowableInformation;
/** Layout for formatting error log events in the JSON format. */
public class ErrorLogJsonLayout extends JsonLayout {
@Override
public DateTimeFormatter createDateTimeFormatter() {
return DateTimeFormatter.ofPattern("yyyy-MM-dd'T'HH:mm:ss.SSSZ");
}
@Override
public JsonLogEntry toJsonLogEntry(LoggingEvent event) {
return new ErrorJsonLogEntry(event);
@@ -85,7 +79,7 @@ public class ErrorLogJsonLayout extends JsonLayout {
public Map<String, String> exception;
public ErrorJsonLogEntry(LoggingEvent event) {
this.timestamp = formatDate(event.getTimeStamp());
this.timestamp = timestampFormatter.format(event.getTimeStamp());
this.sourceHost = getSourceHost();
this.message = event.getRenderedMessage();
this.file = event.getLocationInformation().getFileName();

8
java/com/google/gerrit/sshd/SshLogJsonLayout.java
View File

@@ -25,16 +25,10 @@ import static com.google.gerrit.sshd.SshLog.P_WAIT;
import com.google.gerrit.util.logging.JsonLayout;
import com.google.gerrit.util.logging.JsonLogEntry;
import java.time.format.DateTimeFormatter;
import org.apache.log4j.spi.LoggingEvent;
public class SshLogJsonLayout extends JsonLayout {
@Override
public DateTimeFormatter createDateTimeFormatter() {
return DateTimeFormatter.ofPattern("yyyy-MM-dd HH:mm:ss,SSS Z");
}
@Override
public JsonLogEntry toJsonLogEntry(LoggingEvent event) {
return new SshJsonLogEntry(event);
@@ -65,7 +59,7 @@ public class SshLogJsonLayout extends JsonLayout {
public String bytesTotal;
public SshJsonLogEntry(LoggingEvent event) {
this.timestamp = formatDate(event.getTimeStamp());
this.timestamp = timestampFormatter.format(event.getTimeStamp());
this.session = getMdcString(event, P_SESSION);
this.thread = event.getThreadName();
this.user = getMdcString(event, P_USER_NAME);

54
java/com/google/gerrit/sshd/SshLogLayout.java
View File

@@ -23,27 +23,16 @@ import static com.google.gerrit.sshd.SshLog.P_STATUS;
import static com.google.gerrit.sshd.SshLog.P_USER_NAME;
import static com.google.gerrit.sshd.SshLog.P_WAIT;
import java.text.SimpleDateFormat;
import java.util.Calendar;
import java.util.TimeZone;
import com.google.gerrit.util.logging.LogTimestampFormatter;
import org.apache.log4j.Layout;
import org.apache.log4j.spi.LoggingEvent;
import org.eclipse.jgit.util.QuotedString;
public final class SshLogLayout extends Layout {
private final Calendar calendar;
private long lastTimeMillis;
private final char[] lastTimeString = new char[20];
private final SimpleDateFormat tzFormat;
private char[] timeZone;
protected final LogTimestampFormatter timestampFormatter;
public SshLogLayout() {
final TimeZone tz = TimeZone.getDefault();
calendar = Calendar.getInstance(tz);
tzFormat = new SimpleDateFormat("Z");
tzFormat.setTimeZone(tz);
timestampFormatter = new LogTimestampFormatter();
}
@Override
@@ -51,7 +40,7 @@ public final class SshLogLayout extends Layout {
final StringBuffer buf = new StringBuffer(128);
buf.append('[');
formatDate(event.getTimeStamp(), buf);
buf.append(timestampFormatter.format(event.getTimeStamp()));
buf.append(']');
req(P_SESSION, buf, event);
@@ -77,41 +66,6 @@ public final class SshLogLayout extends Layout {
return buf.toString();
}
private void formatDate(long now, StringBuffer sbuf) {
final int millis = (int) (now % 1000);
final long rounded = now - millis;
if (rounded != lastTimeMillis) {
synchronized (calendar) {
final int start = sbuf.length();
calendar.setTimeInMillis(rounded);
sbuf.append(calendar.get(Calendar.YEAR));
sbuf.append('-');
sbuf.append(toTwoDigits(calendar.get(Calendar.MONTH) + 1));
sbuf.append('-');
sbuf.append(toTwoDigits(calendar.get(Calendar.DAY_OF_MONTH)));
sbuf.append(' ');
sbuf.append(toTwoDigits(calendar.get(Calendar.HOUR_OF_DAY)));
sbuf.append(':');
sbuf.append(toTwoDigits(calendar.get(Calendar.MINUTE)));
sbuf.append(':');
sbuf.append(toTwoDigits(calendar.get(Calendar.SECOND)));
sbuf.append(',');
sbuf.getChars(start, sbuf.length(), lastTimeString, 0);
lastTimeMillis = rounded;
timeZone = tzFormat.format(calendar.getTime()).toCharArray();
}
} else {
sbuf.append(lastTimeString);
}
sbuf.append(String.format("%03d", millis));
sbuf.append(' ');
sbuf.append(timeZone);
}
private String toTwoDigits(int input) {
return String.format("%02d", input);
}
private void req(String key, StringBuffer buf, LoggingEvent event) {
Object val = event.getMDC(key);
buf.append(' ');

22
java/com/google/gerrit/util/logging/JsonLayout.java
View File

@@ -17,30 +17,18 @@ package com.google.gerrit.util.logging;
import com.google.gson.FieldNamingPolicy;
import com.google.gson.Gson;
import com.google.gson.GsonBuilder;
import java.time.Instant;
import java.time.LocalDateTime;
import java.time.OffsetDateTime;
import java.time.ZoneId;
import java.time.ZoneOffset;
import java.time.ZonedDateTime;
import java.time.format.DateTimeFormatter;
import org.apache.log4j.Layout;
import org.apache.log4j.spi.LoggingEvent;
public abstract class JsonLayout extends Layout {
private final DateTimeFormatter dateFormatter;
private final Gson gson;
private final ZoneOffset timeOffset;
protected final LogTimestampFormatter timestampFormatter;
public JsonLayout() {
dateFormatter = createDateTimeFormatter();
timeOffset = OffsetDateTime.now(ZoneId.systemDefault()).getOffset();
timestampFormatter = new LogTimestampFormatter();
gson = newGson();
}
public abstract DateTimeFormatter createDateTimeFormatter();
public abstract JsonLogEntry toJsonLogEntry(LoggingEvent event);
@Override
@@ -56,12 +44,6 @@ public abstract class JsonLayout extends Layout {
return gb.create();
}
public String formatDate(long now) {
return ZonedDateTime.of(
LocalDateTime.ofInstant(Instant.ofEpochMilli(now), timeOffset), ZoneId.systemDefault())
.format(dateFormatter);
}
@Override
public void activateOptions() {}

49
java/com/google/gerrit/util/logging/LogTimestampFormatter.java Normal file
View File

@@ -0,0 +1,49 @@
// Copyright (C) 2020 The Android Open Source Project
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
package com.google.gerrit.util.logging;
import java.time.Instant;
import java.time.LocalDateTime;
import java.time.OffsetDateTime;
import java.time.ZoneId;
import java.time.ZoneOffset;
import java.time.ZonedDateTime;
import java.time.format.DateTimeFormatter;
/** Formatter for timestamps used in log entries. */
public class LogTimestampFormatter {
public static final String TIMESTAMP_FORMAT = "yyyy-MM-dd'T'HH:mm:ss.SSSZ";
private final DateTimeFormatter dateFormatter;
private final ZoneOffset timeOffset;
public LogTimestampFormatter() {
dateFormatter = DateTimeFormatter.ofPattern(TIMESTAMP_FORMAT);
timeOffset = OffsetDateTime.now(ZoneId.systemDefault()).getOffset();
}
/**
* Formats time given in milliseconds since UNIX epoch to ISO 8601 format.
*
* @param epochMilli milliseconds since UNIX epoch
* @return ISO 8601-formatted timestamp
*/
public String format(long epochMilli) {
return ZonedDateTime.of(
LocalDateTime.ofInstant(Instant.ofEpochMilli(epochMilli), timeOffset),
ZoneId.systemDefault())
.format(dateFormatter);
}
}