diff options
Diffstat (limited to 'container-core/src/main/java/com/yahoo/container')
23 files changed, 2333 insertions, 0 deletions
diff --git a/container-core/src/main/java/com/yahoo/container/logging/AccessLog.java b/container-core/src/main/java/com/yahoo/container/logging/AccessLog.java new file mode 100644 index 00000000000..2d46c53bca7 --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/AccessLog.java @@ -0,0 +1,36 @@ +// Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + + +import com.google.inject.Inject; +import com.yahoo.component.provider.ComponentRegistry; + +/** + * Logs to all the configured access logs. + * + * @author Tony Vaagenes + * @author bjorncs + */ +public class AccessLog implements RequestLog { + + public static final AccessLog NONE_INSTANCE = new AccessLog(new ComponentRegistry<>()); + + private final ComponentRegistry<RequestLogHandler> implementers; + + @Inject + public AccessLog(ComponentRegistry<RequestLogHandler> implementers) { + this.implementers = implementers; + } + + public static AccessLog voidAccessLog() { + return NONE_INSTANCE; + } + + @Override + public void log(RequestLogEntry entry) { + for (RequestLogHandler handler: implementers.allComponents()) { + handler.log(entry); + } + } + +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/AccessLogEntry.java b/container-core/src/main/java/com/yahoo/container/logging/AccessLogEntry.java new file mode 100644 index 00000000000..42285fb85bb --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/AccessLogEntry.java @@ -0,0 +1,112 @@ +// Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +import com.yahoo.collections.ListMap; +import com.yahoo.yolean.trace.TraceNode; + +import java.util.ArrayList; +import java.util.Collections; +import java.util.List; +import java.util.Map; +import java.util.Set; +import java.util.function.Function; + +import static java.util.stream.Collectors.toMap; + +/** + * <p>Information to be logged in the access log.</p> + * + * <p>This class contains the union of all information that can be + * logged with all the supported access log formats.</p> + * + * <p>The add methods can be called multiple times, + * but the parameters should be different for each + * invocation of the same method.</p> + * + * This class is thread-safe. + * + * @author Tony Vaagenes + * @author bakksjo + * @author bjorncs + */ +public class AccessLogEntry { + + private final Object monitor = new Object(); + + private HitCounts hitCounts; + private TraceNode traceNode; + private ListMap<String,String> keyValues=null; + + public void setHitCounts(final HitCounts hitCounts) { + synchronized (monitor) { + requireNull(this.hitCounts); + this.hitCounts = hitCounts; + } + } + + public HitCounts getHitCounts() { + synchronized (monitor) { + return hitCounts; + } + } + + public void addKeyValue(String key,String value) { + synchronized (monitor) { + if (keyValues == null) { + keyValues = new ListMap<>(); + } + keyValues.put(key,value); + } + } + + public Map<String, List<String>> getKeyValues() { + synchronized (monitor) { + if (keyValues == null) { + return null; + } + + final Map<String, List<String>> newMapWithImmutableValues = mapValues( + keyValues.entrySet(), + valueList -> Collections.unmodifiableList(new ArrayList<>(valueList))); + return Collections.unmodifiableMap(newMapWithImmutableValues); + } + } + + private static <K, V1, V2> Map<K, V2> mapValues( + final Set<Map.Entry<K, V1>> entrySet, + final Function<V1, V2> valueConverter) { + return entrySet.stream() + .collect(toMap( + entry -> entry.getKey(), + entry -> valueConverter.apply(entry.getValue()))); + } + + public void setTrace(TraceNode traceNode) { + synchronized (monitor) { + requireNull(this.traceNode); + this.traceNode = traceNode; + } + } + + public TraceNode getTrace() { + synchronized (monitor) { + return traceNode; + } + } + + @Override + public String toString() { + return "AccessLogEntry{" + + "hitCounts=" + hitCounts + + ", traceNode=" + traceNode + + ", keyValues=" + keyValues + + '}'; + } + + private static void requireNull(final Object value) { + if (value != null) { + throw new IllegalStateException("Attempt to overwrite field that has been assigned. Value: " + value); + } + } + +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/AccessLogHandler.java b/container-core/src/main/java/com/yahoo/container/logging/AccessLogHandler.java new file mode 100644 index 00000000000..89aab1513ee --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/AccessLogHandler.java @@ -0,0 +1,36 @@ +// Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +import com.yahoo.container.core.AccessLogConfig; + +/** + * @author Bjorn Borud + */ +class AccessLogHandler { + + private final LogFileHandler<RequestLogEntry> logFileHandler; + + AccessLogHandler(AccessLogConfig.FileHandler config, LogWriter<RequestLogEntry> logWriter) { + logFileHandler = new LogFileHandler<>( + toCompression(config), config.pattern(), config.rotation(), + config.symlink(), config.queueSize(), "request-logger", logWriter); + } + + public void log(RequestLogEntry entry) { + logFileHandler.publish(entry); + } + + private LogFileHandler.Compression toCompression(AccessLogConfig.FileHandler config) { + if (!config.compressOnRotation()) return LogFileHandler.Compression.NONE; + switch (config.compressionFormat()) { + case ZSTD: return LogFileHandler.Compression.ZSTD; + case GZIP: return LogFileHandler.Compression.GZIP; + default: throw new IllegalArgumentException(config.compressionFormat().toString()); + } + } + + void shutdown() { + logFileHandler.close(); + logFileHandler.shutdown(); + } +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/CircularArrayAccessLogKeeper.java b/container-core/src/main/java/com/yahoo/container/logging/CircularArrayAccessLogKeeper.java new file mode 100644 index 00000000000..dc749c71613 --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/CircularArrayAccessLogKeeper.java @@ -0,0 +1,48 @@ +// Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +import java.util.ArrayDeque; +import java.util.ArrayList; +import java.util.Deque; +import java.util.List; + +/** + * This class keeps some information from the access log from the requests in memory. It is thread-safe. + * + * @author dybis + */ +public class CircularArrayAccessLogKeeper { + public static final int SIZE = 1000; + private final Deque<String> uris = new ArrayDeque<>(SIZE); + private final Object monitor = new Object(); + + /** + * This class is intended to be used with injection so it can be shared between other classes. + */ + public CircularArrayAccessLogKeeper() {} + + /** + * Creates a list of Uris. + * @return URIs as string + */ + public List<String> getUris() { + final List<String> uriList = new ArrayList<>(); + synchronized (monitor) { + uris.iterator().forEachRemaining(uri -> uriList.add(uri)); + } + return uriList; + } + + /** + * Add a new URI. It might remove an old entry to make space for new entry. + * @param uri uri as string + */ + public void addUri(String uri) { + synchronized (monitor) { + if (uris.size() == SIZE) { + uris.pop(); + } + uris.add(uri); + } + } +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/ConnectionLog.java b/container-core/src/main/java/com/yahoo/container/logging/ConnectionLog.java new file mode 100644 index 00000000000..310231a4a1e --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/ConnectionLog.java @@ -0,0 +1,10 @@ +// Copyright Verizon Media. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. + +package com.yahoo.container.logging; + +/** + * @author mortent + */ +public interface ConnectionLog { + void log(ConnectionLogEntry connectionLogEntry); +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/ConnectionLogEntry.java b/container-core/src/main/java/com/yahoo/container/logging/ConnectionLogEntry.java new file mode 100644 index 00000000000..6afe3b74329 --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/ConnectionLogEntry.java @@ -0,0 +1,225 @@ +// Copyright Verizon Media. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. + +package com.yahoo.container.logging; + +import java.time.Instant; +import java.util.List; +import java.util.Optional; +import java.util.UUID; + +/** + * @author mortent + */ +public class ConnectionLogEntry { + + private final UUID id; + private final Instant timestamp; + private final Double durationSeconds; + private final String peerAddress; + private final Integer peerPort; + private final String localAddress; + private final Integer localPort; + private final String remoteAddress; + private final Integer remotePort; + private final Long httpBytesReceived; + private final Long httpBytesSent; + private final Long requests; + private final Long responses; + private final String sslSessionId; + private final String sslProtocol; + private final String sslCipherSuite; + private final String sslPeerSubject; + private final Instant sslPeerNotBefore; + private final Instant sslPeerNotAfter; + private final String sslSniServerName; + private final SslHandshakeFailure sslHandshakeFailure; + + + private ConnectionLogEntry(Builder builder) { + this.id = builder.id; + this.timestamp = builder.timestamp; + this.durationSeconds = builder.durationSeconds; + this.peerAddress = builder.peerAddress; + this.peerPort = builder.peerPort; + this.localAddress = builder.localAddress; + this.localPort = builder.localPort; + this.remoteAddress = builder.remoteAddress; + this.remotePort = builder.remotePort; + this.httpBytesReceived = builder.httpBytesReceived; + this.httpBytesSent = builder.httpBytesSent; + this.requests = builder.requests; + this.responses = builder.responses; + this.sslSessionId = builder.sslSessionId; + this.sslProtocol = builder.sslProtocol; + this.sslCipherSuite = builder.sslCipherSuite; + this.sslPeerSubject = builder.sslPeerSubject; + this.sslPeerNotBefore = builder.sslPeerNotBefore; + this.sslPeerNotAfter = builder.sslPeerNotAfter; + this.sslSniServerName = builder.sslSniServerName; + this.sslHandshakeFailure = builder.sslHandshakeFailure; + } + + public static Builder builder(UUID id, Instant timestamp) { + return new Builder(id, timestamp); + } + + public String id() { return id.toString(); } + public Instant timestamp() { return timestamp; } + public Optional<Double> durationSeconds() { return Optional.ofNullable(durationSeconds); } + public Optional<String> peerAddress() { return Optional.ofNullable(peerAddress); } + public Optional<Integer> peerPort() { return Optional.ofNullable(peerPort); } + public Optional<String> localAddress() { return Optional.ofNullable(localAddress); } + public Optional<Integer> localPort() { return Optional.ofNullable(localPort); } + public Optional<String> remoteAddress() { return Optional.ofNullable(remoteAddress); } + public Optional<Integer> remotePort() { return Optional.ofNullable(remotePort); } + public Optional<Long> httpBytesReceived() { return Optional.ofNullable(httpBytesReceived); } + public Optional<Long> httpBytesSent() { return Optional.ofNullable(httpBytesSent); } + public Optional<Long> requests() { return Optional.ofNullable(requests); } + public Optional<Long> responses() { return Optional.ofNullable(responses); } + public Optional<String> sslSessionId() { return Optional.ofNullable(sslSessionId); } + public Optional<String> sslProtocol() { return Optional.ofNullable(sslProtocol); } + public Optional<String> sslCipherSuite() { return Optional.ofNullable(sslCipherSuite); } + public Optional<String> sslPeerSubject() { return Optional.ofNullable(sslPeerSubject); } + public Optional<Instant> sslPeerNotBefore() { return Optional.ofNullable(sslPeerNotBefore); } + public Optional<Instant> sslPeerNotAfter() { return Optional.ofNullable(sslPeerNotAfter); } + public Optional<String> sslSniServerName() { return Optional.ofNullable(sslSniServerName); } + public Optional<SslHandshakeFailure> sslHandshakeFailure() { return Optional.ofNullable(sslHandshakeFailure); } + + public static class SslHandshakeFailure { + private final String type; + private final List<ExceptionEntry> exceptionChain; + + public SslHandshakeFailure(String type, List<ExceptionEntry> exceptionChain) { + this.type = type; + this.exceptionChain = List.copyOf(exceptionChain); + } + + public String type() { return type; } + public List<ExceptionEntry> exceptionChain() { return exceptionChain; } + + public static class ExceptionEntry { + private final String name; + private final String message; + + public ExceptionEntry(String name, String message) { + this.name = name; + this.message = message; + } + + public String name() { return name; } + public String message() { return message; } + } + } + + public static class Builder { + private final UUID id; + private final Instant timestamp; + private Double durationSeconds; + private String peerAddress; + private Integer peerPort; + private String localAddress; + private Integer localPort; + private String remoteAddress; + private Integer remotePort; + private Long httpBytesReceived; + private Long httpBytesSent; + private Long requests; + private Long responses; + private String sslSessionId; + private String sslProtocol; + private String sslCipherSuite; + private String sslPeerSubject; + private Instant sslPeerNotBefore; + private Instant sslPeerNotAfter; + private String sslSniServerName; + private SslHandshakeFailure sslHandshakeFailure; + + + Builder(UUID id, Instant timestamp) { + this.id = id; + this.timestamp = timestamp; + } + + public Builder withDuration(double durationSeconds) { + this.durationSeconds = durationSeconds; + return this; + } + + public Builder withPeerAddress(String peerAddress) { + this.peerAddress = peerAddress; + return this; + } + public Builder withPeerPort(int peerPort) { + this.peerPort = peerPort; + return this; + } + public Builder withLocalAddress(String localAddress) { + this.localAddress = localAddress; + return this; + } + public Builder withLocalPort(int localPort) { + this.localPort = localPort; + return this; + } + public Builder withRemoteAddress(String remoteAddress) { + this.remoteAddress = remoteAddress; + return this; + } + public Builder withRemotePort(int remotePort) { + this.remotePort = remotePort; + return this; + } + public Builder withHttpBytesReceived(long bytesReceived) { + this.httpBytesReceived = bytesReceived; + return this; + } + public Builder withHttpBytesSent(long bytesSent) { + this.httpBytesSent = bytesSent; + return this; + } + public Builder withRequests(long requests) { + this.requests = requests; + return this; + } + public Builder withResponses(long responses) { + this.responses = responses; + return this; + } + public Builder withSslSessionId(String sslSessionId) { + this.sslSessionId = sslSessionId; + return this; + } + public Builder withSslProtocol(String sslProtocol) { + this.sslProtocol = sslProtocol; + return this; + } + public Builder withSslCipherSuite(String sslCipherSuite) { + this.sslCipherSuite = sslCipherSuite; + return this; + } + public Builder withSslPeerSubject(String sslPeerSubject) { + this.sslPeerSubject = sslPeerSubject; + return this; + } + public Builder withSslPeerNotBefore(Instant sslPeerNotBefore) { + this.sslPeerNotBefore = sslPeerNotBefore; + return this; + } + public Builder withSslPeerNotAfter(Instant sslPeerNotAfter) { + this.sslPeerNotAfter = sslPeerNotAfter; + return this; + } + public Builder withSslSniServerName(String sslSniServerName) { + this.sslSniServerName = sslSniServerName; + return this; + } + public Builder withSslHandshakeFailure(SslHandshakeFailure sslHandshakeFailure) { + this.sslHandshakeFailure = sslHandshakeFailure; + return this; + } + + public ConnectionLogEntry build(){ + return new ConnectionLogEntry(this); + } + } +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/ConnectionLogHandler.java b/container-core/src/main/java/com/yahoo/container/logging/ConnectionLogHandler.java new file mode 100644 index 00000000000..7a0e8aca95e --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/ConnectionLogHandler.java @@ -0,0 +1,30 @@ +// Copyright Verizon Media. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. + +package com.yahoo.container.logging; + +/** + * @author mortent + */ +class ConnectionLogHandler { + private final LogFileHandler<ConnectionLogEntry> logFileHandler; + + public ConnectionLogHandler(String logDirectoryName, String clusterName, int queueSize, LogWriter<ConnectionLogEntry> logWriter) { + logFileHandler = new LogFileHandler<>( + LogFileHandler.Compression.ZSTD, + String.format("logs/vespa/%s/ConnectionLog.%s.%s", logDirectoryName, clusterName, "%Y%m%d%H%M%S"), + "0 60 ...", + String.format("ConnectionLog.%s", clusterName), + queueSize, + "connection-logger", + logWriter); + } + + public void log(ConnectionLogEntry entry) { + logFileHandler.publish(entry); + } + + public void shutdown() { + logFileHandler.close(); + logFileHandler.shutdown(); + } +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/Coverage.java b/container-core/src/main/java/com/yahoo/container/logging/Coverage.java new file mode 100644 index 00000000000..9d122b90641 --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/Coverage.java @@ -0,0 +1,64 @@ +// Copyright 2020 Oath Inc. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +/** + * Carry information about how the query covered the document corpus. + */ +public class Coverage { + private final long docs; + private final long active; + private final long soonActive; + private final int degradedReason; + private final static int DEGRADED_BY_MATCH_PHASE = 1; + private final static int DEGRADED_BY_TIMEOUT = 2; + private final static int DEGRADED_BY_ADAPTIVE_TIMEOUT = 4; + public Coverage(long docs, long active, long soonActive, int degradedReason) { + this.docs = docs; + this.active = active; + this.soonActive = soonActive; + this.degradedReason = degradedReason; + } + + public long getDocs() { + return docs; + } + + public long getActive() { + return active; + } + + public static int toDegradation(boolean degradeByMatchPhase, boolean degradedByTimeout, boolean degradedByAdaptiveTimeout) { + int v = 0; + if (degradeByMatchPhase) { + v |= DEGRADED_BY_MATCH_PHASE; + } + if (degradedByTimeout) { + v |= DEGRADED_BY_TIMEOUT; + } + if (degradedByAdaptiveTimeout) { + v |= DEGRADED_BY_ADAPTIVE_TIMEOUT; + } + return v; + } + + public long getSoonActive() { return soonActive; } + + public boolean isDegraded() { return (degradedReason != 0) || isDegradedByNonIdealState(); } + public boolean isDegradedByMatchPhase() { return (degradedReason & DEGRADED_BY_MATCH_PHASE) != 0; } + public boolean isDegradedByTimeout() { return (degradedReason & DEGRADED_BY_TIMEOUT) != 0; } + public boolean isDegradedByAdapativeTimeout() { return (degradedReason & DEGRADED_BY_ADAPTIVE_TIMEOUT) != 0; } + public boolean isDegradedByNonIdealState() { return (degradedReason == 0) && (getResultPercentage() != 100);} + + /** + * An int between 0 (inclusive) and 100 (inclusive) representing how many + * percent coverage the result sets this Coverage instance contains information + * about had. + */ + public int getResultPercentage() { + if (docs < active) { + return (int) Math.round(docs * 100.0d / active); + } + return 100; + } + +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/FileConnectionLog.java b/container-core/src/main/java/com/yahoo/container/logging/FileConnectionLog.java new file mode 100644 index 00000000000..7432c313286 --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/FileConnectionLog.java @@ -0,0 +1,30 @@ +// Copyright Verizon Media. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. + +package com.yahoo.container.logging; + +import com.google.inject.Inject; +import com.yahoo.component.AbstractComponent; + +/** + * @author mortent + */ +public class FileConnectionLog extends AbstractComponent implements ConnectionLog { + + private final ConnectionLogHandler logHandler; + + @Inject + public FileConnectionLog(ConnectionLogConfig config) { + logHandler = new ConnectionLogHandler(config.logDirectoryName(), config.cluster(), config.queueSize(), new JsonConnectionLogWriter()); + } + + @Override + public void log(ConnectionLogEntry connectionLogEntry) { + logHandler.log(connectionLogEntry); + } + + @Override + public void deconstruct() { + logHandler.shutdown(); + } + +}
\ No newline at end of file diff --git a/container-core/src/main/java/com/yahoo/container/logging/FormatUtil.java b/container-core/src/main/java/com/yahoo/container/logging/FormatUtil.java new file mode 100644 index 00000000000..ee780ad2a83 --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/FormatUtil.java @@ -0,0 +1,46 @@ +// Copyright Verizon Media. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +import com.fasterxml.jackson.core.JsonGenerator; + +import java.io.IOException; +import java.time.Duration; +import java.time.Instant; + +/** + * @author bjorncs + */ +class FormatUtil { + + private FormatUtil() {} + + static void writeSecondsField(JsonGenerator generator, String fieldName, Instant instant) throws IOException { + writeSecondsField(generator, fieldName, instant.toEpochMilli()); + } + + static void writeSecondsField(JsonGenerator generator, String fieldName, Duration duration) throws IOException { + writeSecondsField(generator, fieldName, duration.toMillis()); + } + + static void writeSecondsField(JsonGenerator generator, String fieldName, double seconds) throws IOException { + writeSecondsField(generator, fieldName, (long)(seconds * 1000)); + } + + static void writeSecondsField(JsonGenerator generator, String fieldName, long milliseconds) throws IOException { + generator.writeFieldName(fieldName); + generator.writeRawValue(toSecondsString(milliseconds)); + } + + /** @return a string with number of seconds with 3 decimals */ + static String toSecondsString(long milliseconds) { + StringBuilder builder = new StringBuilder().append(milliseconds / 1000L).append('.'); + long decimals = milliseconds % 1000; + if (decimals < 100) { + builder.append('0'); + if (decimals < 10) { + builder.append('0'); + } + } + return builder.append(decimals).toString(); + } +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/HitCounts.java b/container-core/src/main/java/com/yahoo/container/logging/HitCounts.java new file mode 100644 index 00000000000..fed12281962 --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/HitCounts.java @@ -0,0 +1,78 @@ +// Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +/** + * A wrapper for hit counts, modelled after a search system. + * Advanced database searches and similar could use these + * structures as well. + * + * @author <a href="mailto:steinar@yahoo-inc.com">Steinar Knutsen</a> + */ +public class HitCounts { + + // see the javadoc for the accessors for short comments on each field + private final int retrievedHits; + private final int summaryCount; + private final long totalHitCount; + private final int requestedHits; + private final int requestedOffset; + private final Coverage coverage; + + HitCounts(int retrievedHits, int summaryCount, long totalHitCount, int requestedHits, int requestedOffset) { + this(retrievedHits, summaryCount, totalHitCount, requestedHits, requestedOffset, + new Coverage(1,1,1,0)); + } + + public HitCounts(int retrievedHits, int summaryCount, long totalHitCount, + int requestedHits, int requestedOffset, Coverage coverage) + { + + this.retrievedHits = retrievedHits; + this.summaryCount = summaryCount; + this.totalHitCount = totalHitCount; + this.requestedHits = requestedHits; + this.requestedOffset = requestedOffset; + this.coverage = coverage; + } + + /** + * The number of hits returned by the server. + * Compare to getRequestedHits(). + */ + public int getRetrievedHitCount() { + return retrievedHits; + } + + /** + * The number of hit summaries ("document contents") fetched. + */ + public int getSummaryCount() { + return summaryCount; + } + + /** + * The total number of matching hits + * for the request. + */ + public long getTotalHitCount() { + return totalHitCount; + } + + /** + * The number of hits requested by the user. + * Compare to getRetrievedHitCount(). + */ + public int getRequestedHits() { + return requestedHits; + } + + /** + * The user requested offset into the linear mapping of the result space. + */ + public int getRequestedOffset() { + return requestedOffset; + } + + public Coverage getCoverage() { return coverage; } + +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/JSONAccessLog.java b/container-core/src/main/java/com/yahoo/container/logging/JSONAccessLog.java new file mode 100644 index 00000000000..ece9d0d2c4a --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/JSONAccessLog.java @@ -0,0 +1,27 @@ +// Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +import com.yahoo.component.AbstractComponent; +import com.yahoo.container.core.AccessLogConfig; + +/** + * Log a message in Vespa JSON access log format. + * + * @author frodelu + * @author Tony Vaagenes + */ +public final class JSONAccessLog extends AbstractComponent implements RequestLogHandler { + + private final AccessLogHandler logHandler; + + public JSONAccessLog(AccessLogConfig config) { + logHandler = new AccessLogHandler(config.fileHandler(), new JSONFormatter()); + } + + @Override + public void log(RequestLogEntry entry) { + logHandler.log(entry); + } + + @Override public void deconstruct() { logHandler.shutdown(); } +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/JSONFormatter.java b/container-core/src/main/java/com/yahoo/container/logging/JSONFormatter.java new file mode 100644 index 00000000000..680ee5acbd9 --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/JSONFormatter.java @@ -0,0 +1,193 @@ +// Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +import com.fasterxml.jackson.core.JsonEncoding; +import com.fasterxml.jackson.core.JsonFactory; +import com.fasterxml.jackson.core.JsonGenerator; +import com.fasterxml.jackson.databind.ObjectMapper; +import com.yahoo.yolean.trace.TraceNode; + +import java.io.IOException; +import java.io.OutputStream; +import java.security.Principal; +import java.util.Collection; +import java.util.Objects; +import java.util.logging.Level; +import java.util.logging.Logger; + +/** + * Formatting of an {@link AccessLogEntry} in the Vespa JSON access log format. + * + * @author frodelu + */ +public class JSONFormatter implements LogWriter<RequestLogEntry> { + private static final String COVERAGE = "coverage"; + private static final String COVERAGE_COVERAGE = "coverage"; + private static final String COVERAGE_DOCUMENTS = "documents"; + private static final String COVERAGE_DEGRADE = "degraded"; + private static final String COVERAGE_DEGRADE_MATCHPHASE = "match-phase"; + private static final String COVERAGE_DEGRADE_TIMEOUT = "timeout"; + private static final String COVERAGE_DEGRADE_ADAPTIVE_TIMEOUT = "adaptive-timeout"; + private static final String COVERAGE_DEGRADED_NON_IDEAL_STATE = "non-ideal-state"; + + private final JsonFactory generatorFactory; + + private static Logger logger = Logger.getLogger(JSONFormatter.class.getName()); + + public JSONFormatter() { + generatorFactory = new JsonFactory(new ObjectMapper()); + } + + @Override + public void write(RequestLogEntry entry, OutputStream outputStream) throws IOException { + try (JsonGenerator generator = createJsonGenerator(outputStream)){ + generator.writeStartObject(); + String peerAddress = entry.peerAddress().get(); + generator.writeStringField("ip", peerAddress); + long time = entry.timestamp().get().toEpochMilli(); + FormatUtil.writeSecondsField(generator, "time", time); + FormatUtil.writeSecondsField(generator, "duration", entry.duration().get()); + generator.writeNumberField("responsesize", entry.contentSize().orElse(0)); + generator.writeNumberField("code", entry.statusCode().orElse(0)); + generator.writeStringField("method", entry.httpMethod().orElse("")); + generator.writeStringField("uri", getNormalizedURI(entry.rawPath().orElse(null), entry.rawQuery().orElse(null))); + generator.writeStringField("version", entry.httpVersion().orElse("")); + generator.writeStringField("agent", entry.userAgent().orElse("")); + generator.writeStringField("host", entry.hostString().orElse("")); + generator.writeStringField("scheme", entry.scheme().orElse(null)); + generator.writeNumberField("localport", entry.localPort().getAsInt()); + + String connectionId = entry.connectionId().orElse(null); + if (connectionId != null) { + generator.writeStringField("connection", connectionId); + } + + Principal userPrincipal = entry.userPrincipal().orElse(null); + if (userPrincipal != null) { + generator.writeStringField("user-principal", userPrincipal.getName()); + } + + Principal sslPrincipal = entry.sslPrincipal().orElse(null); + if (sslPrincipal != null) { + generator.writeStringField("ssl-principal", sslPrincipal.getName()); + } + + String remoteAddress = entry.remoteAddress().orElse(null); + int remotePort = entry.remotePort().orElse(0); + // Only add remote address/port fields if relevant + if (remoteAddressDiffers(peerAddress, remoteAddress)) { + generator.writeStringField("remoteaddr", remoteAddress); + if (remotePort > 0) { + generator.writeNumberField("remoteport", remotePort); + } + } + + // Only add peer address/port fields if relevant + if (peerAddress != null) { + generator.writeStringField("peeraddr", peerAddress); + + int peerPort = entry.peerPort().getAsInt(); + if (peerPort > 0 && peerPort != remotePort) { + generator.writeNumberField("peerport", peerPort); + } + } + + TraceNode trace = entry.traceNode().orElse(null); + if (trace != null) { + long timestamp = trace.timestamp(); + if (timestamp == 0L) { + timestamp = time; + } + trace.accept(new TraceRenderer(generator, timestamp)); + } + + // Only add search sub block of this is a search request + if (isSearchRequest(entry)) { + HitCounts hitCounts = entry.hitCounts().get(); + generator.writeObjectFieldStart("search"); + generator.writeNumberField("totalhits", getTotalHitCount(hitCounts)); + generator.writeNumberField("hits", getRetrievedHitCount(hitCounts)); + Coverage c = hitCounts.getCoverage(); + if (c != null) { + generator.writeObjectFieldStart(COVERAGE); + generator.writeNumberField(COVERAGE_COVERAGE, c.getResultPercentage()); + generator.writeNumberField(COVERAGE_DOCUMENTS, c.getDocs()); + if (c.isDegraded()) { + generator.writeObjectFieldStart(COVERAGE_DEGRADE); + if (c.isDegradedByMatchPhase()) + generator.writeBooleanField(COVERAGE_DEGRADE_MATCHPHASE, c.isDegradedByMatchPhase()); + if (c.isDegradedByTimeout()) + generator.writeBooleanField(COVERAGE_DEGRADE_TIMEOUT, c.isDegradedByTimeout()); + if (c.isDegradedByAdapativeTimeout()) + generator.writeBooleanField(COVERAGE_DEGRADE_ADAPTIVE_TIMEOUT, c.isDegradedByAdapativeTimeout()); + if (c.isDegradedByNonIdealState()) + generator.writeBooleanField(COVERAGE_DEGRADED_NON_IDEAL_STATE, c.isDegradedByNonIdealState()); + generator.writeEndObject(); + } + generator.writeEndObject(); + } + generator.writeEndObject(); + } + + // Add key/value access log entries. Keys with single values are written as single + // string value fields while keys with multiple values are written as string arrays + Collection<String> keys = entry.extraAttributeKeys(); + if (!keys.isEmpty()) { + generator.writeObjectFieldStart("attributes"); + for (String key : keys) { + Collection<String> values = entry.extraAttributeValues(key); + if (values.size() == 1) { + generator.writeStringField(key, values.iterator().next()); + } else { + generator.writeFieldName(key); + generator.writeStartArray(); + for (String s : values) { + generator.writeString(s); + } + generator.writeEndArray(); + } + } + generator.writeEndObject(); + } + + generator.writeEndObject(); + } catch (IOException e) { + logger.log(Level.WARNING, "Unable to generate JSON access log entry: " + e.getMessage(), e); + } + } + + private JsonGenerator createJsonGenerator(OutputStream outputStream) throws IOException { + return generatorFactory.createGenerator(outputStream, JsonEncoding.UTF8) + .configure(JsonGenerator.Feature.AUTO_CLOSE_TARGET, false) + .configure(JsonGenerator.Feature.FLUSH_PASSED_TO_STREAM, false); + } + + private boolean remoteAddressDiffers(String ipV4Address, String remoteAddress) { + return remoteAddress != null && !Objects.equals(ipV4Address, remoteAddress); + } + + private boolean isSearchRequest(RequestLogEntry entry) { + return entry != null && entry.hitCounts().isPresent(); + } + + private long getTotalHitCount(HitCounts counts) { + if (counts == null) { + return 0; + } + + return counts.getTotalHitCount(); + } + + private int getRetrievedHitCount(HitCounts counts) { + if (counts == null) { + return 0; + } + + return counts.getRetrievedHitCount(); + } + + private static String getNormalizedURI(String rawPath, String rawQuery) { + if (rawPath == null) return null; + return rawQuery != null ? rawPath + "?" + rawQuery : rawPath; + } +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/JsonConnectionLogWriter.java b/container-core/src/main/java/com/yahoo/container/logging/JsonConnectionLogWriter.java new file mode 100644 index 00000000000..158d2ec4ea6 --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/JsonConnectionLogWriter.java @@ -0,0 +1,122 @@ +// Copyright Verizon Media. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +import com.fasterxml.jackson.core.JsonEncoding; +import com.fasterxml.jackson.core.JsonFactory; +import com.fasterxml.jackson.core.JsonGenerator; +import com.fasterxml.jackson.databind.ObjectMapper; +import com.yahoo.container.logging.ConnectionLogEntry.SslHandshakeFailure.ExceptionEntry; + +import java.io.IOException; +import java.io.OutputStream; +import java.time.Instant; +import java.util.Arrays; +import java.util.Objects; +import java.util.Optional; + +/** + * @author bjorncs + */ +class JsonConnectionLogWriter implements LogWriter<ConnectionLogEntry> { + + private final JsonFactory jsonFactory = new JsonFactory(new ObjectMapper()); + + @Override + public void write(ConnectionLogEntry record, OutputStream outputStream) throws IOException { + try (JsonGenerator generator = createJsonGenerator(outputStream)) { + generator.writeStartObject(); + generator.writeStringField("id", record.id()); + generator.writeStringField("timestamp", record.timestamp().toString()); + + writeOptionalSeconds(generator, "duration", unwrap(record.durationSeconds())); + writeOptionalString(generator, "peerAddress", unwrap(record.peerAddress())); + writeOptionalInteger(generator, "peerPort", unwrap(record.peerPort())); + writeOptionalString(generator, "localAddress", unwrap(record.localAddress())); + writeOptionalInteger(generator, "localPort", unwrap(record.localPort())); + writeOptionalString(generator, "remoteAddress", unwrap(record.remoteAddress())); + writeOptionalInteger(generator, "remotePort", unwrap(record.remotePort())); + writeOptionalLong(generator, "httpBytesReceived", unwrap(record.httpBytesReceived())); + writeOptionalLong(generator, "httpBytesSent", unwrap(record.httpBytesSent())); + writeOptionalLong(generator, "requests", unwrap(record.requests())); + writeOptionalLong(generator, "responses", unwrap(record.responses())); + + String sslProtocol = unwrap(record.sslProtocol()); + String sslSessionId = unwrap(record.sslSessionId()); + String sslCipherSuite = unwrap(record.sslCipherSuite()); + String sslPeerSubject = unwrap(record.sslPeerSubject()); + Instant sslPeerNotBefore = unwrap(record.sslPeerNotBefore()); + Instant sslPeerNotAfter = unwrap(record.sslPeerNotAfter()); + String sslSniServerName = unwrap(record.sslSniServerName()); + ConnectionLogEntry.SslHandshakeFailure sslHandshakeFailure = unwrap(record.sslHandshakeFailure()); + + if (isAnyValuePresent( + sslProtocol, sslSessionId, sslCipherSuite, sslPeerSubject, sslPeerNotBefore, sslPeerNotAfter, + sslSniServerName, sslHandshakeFailure)) { + generator.writeObjectFieldStart("ssl"); + + writeOptionalString(generator, "protocol", sslProtocol); + writeOptionalString(generator, "sessionId", sslSessionId); + writeOptionalString(generator, "cipherSuite", sslCipherSuite); + writeOptionalString(generator, "peerSubject", sslPeerSubject); + writeOptionalTimestamp(generator, "peerNotBefore", sslPeerNotBefore); + writeOptionalTimestamp(generator, "peerNotAfter", sslPeerNotAfter); + writeOptionalString(generator, "sniServerName", sslSniServerName); + + if (sslHandshakeFailure != null) { + generator.writeObjectFieldStart("handshake-failure"); + generator.writeArrayFieldStart("exception"); + for (ExceptionEntry entry : sslHandshakeFailure.exceptionChain()) { + generator.writeStartObject(); + generator.writeStringField("cause", entry.name()); + generator.writeStringField("message", entry.message()); + generator.writeEndObject(); + } + generator.writeEndArray(); + generator.writeStringField("type", sslHandshakeFailure.type()); + generator.writeEndObject(); + } + + generator.writeEndObject(); + } + } + } + + private void writeOptionalString(JsonGenerator generator, String name, String value) throws IOException { + if (value != null) { + generator.writeStringField(name, value); + } + } + + private void writeOptionalInteger(JsonGenerator generator, String name, Integer value) throws IOException { + if (value != null) { + generator.writeNumberField(name, value); + } + } + + private void writeOptionalLong(JsonGenerator generator, String name, Long value) throws IOException { + if (value != null) { + generator.writeNumberField(name, value); + } + } + + private void writeOptionalTimestamp(JsonGenerator generator, String name, Instant value) throws IOException { + if (value != null) { + generator.writeStringField(name, value.toString()); + } + } + + private void writeOptionalSeconds(JsonGenerator generator, String name, Double value) throws IOException { + if (value != null) { + FormatUtil.writeSecondsField(generator, name, value); + } + } + + private static boolean isAnyValuePresent(Object... values) { return Arrays.stream(values).anyMatch(Objects::nonNull); } + private static <T> T unwrap(Optional<T> maybeValue) { return maybeValue.orElse(null); } + + private JsonGenerator createJsonGenerator(OutputStream outputStream) throws IOException { + return jsonFactory.createGenerator(outputStream, JsonEncoding.UTF8) + .configure(JsonGenerator.Feature.AUTO_CLOSE_TARGET, false) + .configure(JsonGenerator.Feature.FLUSH_PASSED_TO_STREAM, false); + } +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/LogFileHandler.java b/container-core/src/main/java/com/yahoo/container/logging/LogFileHandler.java new file mode 100644 index 00000000000..0f2a9e42eb8 --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/LogFileHandler.java @@ -0,0 +1,563 @@ +// Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +import com.yahoo.compress.ZstdOuputStream; +import com.yahoo.io.NativeIO; +import com.yahoo.log.LogFileDb; +import com.yahoo.protect.Process; +import com.yahoo.yolean.Exceptions; + +import java.io.BufferedOutputStream; +import java.io.File; +import java.io.FileDescriptor; +import java.io.FileInputStream; +import java.io.FileNotFoundException; +import java.io.FileOutputStream; +import java.io.IOException; +import java.io.OutputStream; +import java.nio.file.Files; +import java.nio.file.Path; +import java.nio.file.Paths; +import java.nio.file.StandardCopyOption; +import java.util.ArrayList; +import java.util.Optional; +import java.util.concurrent.BlockingQueue; +import java.util.concurrent.CountDownLatch; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; +import java.util.concurrent.LinkedBlockingQueue; +import java.util.concurrent.TimeUnit; +import java.util.logging.Level; +import java.util.logging.Logger; +import java.util.zip.GZIPOutputStream; + +/** + * Implements log file naming/rotating logic for container logs. + * + * @author Bob Travis + * @author bjorncs + */ +class LogFileHandler <LOGTYPE> { + + enum Compression {NONE, GZIP, ZSTD} + + private final static Logger logger = Logger.getLogger(LogFileHandler.class.getName()); + private final BlockingQueue<Operation<LOGTYPE>> logQueue; + final LogThread<LOGTYPE> logThread; + + @FunctionalInterface private interface Pollable<T> { Operation<T> poll() throws InterruptedException; } + + LogFileHandler(Compression compression, String filePattern, String rotationTimes, String symlinkName, int queueSize, + String threadName, LogWriter<LOGTYPE> logWriter) { + this(compression, filePattern, calcTimesMinutes(rotationTimes), symlinkName, queueSize, threadName, logWriter); + } + + LogFileHandler( + Compression compression, + String filePattern, + long[] rotationTimes, + String symlinkName, + int queueSize, + String threadName, + LogWriter<LOGTYPE> logWriter) { + this.logQueue = new LinkedBlockingQueue<>(queueSize); + this.logThread = new LogThread<>(logWriter, filePattern, compression, rotationTimes, symlinkName, threadName, this::poll); + this.logThread.start(); + } + + private Operation<LOGTYPE> poll() throws InterruptedException { + return logQueue.poll(100, TimeUnit.MILLISECONDS); + } + + /** + * Sends logrecord to file, first rotating file if needed. + * + * @param r logrecord to publish + */ + public void publish(LOGTYPE r) { + addOperation(new Operation<>(r)); + } + + void publishAndWait(LOGTYPE r) { + addOperationAndWait(new Operation<>(r)); + } + + public void flush() { + addOperationAndWait(new Operation<>(Operation.Type.flush)); + } + + /** + * Force file rotation now, independent of schedule. + */ + void rotateNow() { + addOperationAndWait(new Operation<>(Operation.Type.rotate)); + } + + public void close() { + addOperationAndWait(new Operation<>(Operation.Type.close)); + } + + private void addOperation(Operation<LOGTYPE> op) { + try { + logQueue.put(op); + } catch (InterruptedException e) { + } + } + + private void addOperationAndWait(Operation<LOGTYPE> op) { + try { + logQueue.put(op); + op.countDownLatch.await(); + } catch (InterruptedException e) { + } + } + + /** + * Flushes all queued messages, interrupts the log thread in this and + * waits for it to end before returning + */ + void shutdown() { + logThread.interrupt(); + try { + logThread.executor.shutdownNow(); + logThread.executor.awaitTermination(600, TimeUnit.SECONDS); + logThread.join(); + } catch (InterruptedException e) { + } + } + + /** + * Calculate rotation times array, given times in minutes, as "0 60 ..." + */ + private static long[] calcTimesMinutes(String times) { + ArrayList<Long> list = new ArrayList<>(50); + int i = 0; + boolean etc = false; + + while (i < times.length()) { + if (times.charAt(i) == ' ') { + i++; + continue; + } // skip spaces + int j = i; // start of string + i = times.indexOf(' ', i); + if (i == -1) i = times.length(); + if (times.charAt(j) == '.' && times.substring(j, i).equals("...")) { // ... + etc = true; + break; + } + list.add(Long.valueOf(times.substring(j, i))); + } + + int size = list.size(); + long[] longtimes = new long[size]; + for (i = 0; i < size; i++) { + longtimes[i] = list.get(i) // pick up value in minutes past midnight + * 60000; // and multiply to get millis + } + + if (etc) { // fill out rest of day, same as final interval + long endOfDay = 24 * 60 * 60 * 1000; + long lasttime = longtimes[size - 1]; + long interval = lasttime - longtimes[size - 2]; + long moreneeded = (endOfDay - lasttime) / interval; + if (moreneeded > 0) { + int newsize = size + (int) moreneeded; + long[] temp = new long[newsize]; + for (i = 0; i < size; i++) { + temp[i] = longtimes[i]; + } + while (size < newsize) { + lasttime += interval; + temp[size++] = lasttime; + } + longtimes = temp; + } + } + + return longtimes; + } + + /** + * Only for unit testing. Do not use. + */ + String getFileName() { + return logThread.fileName; + } + + /** + * Handle logging and file operations + */ + static class LogThread<LOGTYPE> extends Thread { + private final Pollable<LOGTYPE> operationProvider; + long lastFlush = 0; + private PageCacheFriendlyFileOutputStream fileOutput = null; + private long nextRotationTime = 0; + private final String filePattern; // default to current directory, ms time stamp + private volatile String fileName; + private final LogWriter<LOGTYPE> logWriter; + private final Compression compression; + private final long[] rotationTimes; + private final String symlinkName; + private final ExecutorService executor = createCompressionTaskExecutor(); + private final NativeIO nativeIO = new NativeIO(); + + + LogThread(LogWriter<LOGTYPE> logWriter, + String filePattern, + Compression compression, + long[] rotationTimes, + String symlinkName, + String threadName, + Pollable<LOGTYPE> operationProvider) { + super(threadName); + setDaemon(true); + this.logWriter = logWriter; + this.filePattern = filePattern; + this.compression = compression; + this.rotationTimes = rotationTimes; + this.symlinkName = (symlinkName != null && !symlinkName.isBlank()) ? symlinkName : null; + this.operationProvider = operationProvider; + } + + private static ExecutorService createCompressionTaskExecutor() { + return Executors.newSingleThreadExecutor(runnable -> { + Thread thread = new Thread(runnable, "logfilehandler.compression"); + thread.setDaemon(true); + thread.setPriority(Thread.MIN_PRIORITY); + return thread; + }); + } + + @Override + public void run() { + try { + handleLogOperations(); + } catch (InterruptedException e) { + } catch (Exception e) { + Process.logAndDie("Failed storing log records", e); + } + + internalFlush(); + } + + private void handleLogOperations() throws InterruptedException { + while (!isInterrupted()) { + Operation<LOGTYPE> r = operationProvider.poll(); + if (r != null) { + if (r.type == Operation.Type.flush) { + internalFlush(); + } else if (r.type == Operation.Type.close) { + internalClose(); + } else if (r.type == Operation.Type.rotate) { + internalRotateNow(); + lastFlush = System.nanoTime(); + } else if (r.type == Operation.Type.log) { + internalPublish(r.log.get()); + flushIfOld(3, TimeUnit.SECONDS); + } + r.countDownLatch.countDown(); + } else { + flushIfOld(100, TimeUnit.MILLISECONDS); + } + } + } + + private void flushIfOld(long age, TimeUnit unit) { + long now = System.nanoTime(); + if (TimeUnit.NANOSECONDS.toMillis(now - lastFlush) > unit.toMillis(age)) { + internalFlush(); + lastFlush = now; + } + } + + private void internalFlush() { + try { + if (fileOutput != null) { + fileOutput.flush(); + } + } catch (IOException e) { + logger.log(Level.WARNING, "Failed to flush file output: " + Exceptions.toMessageString(e), e); + } + } + + private void internalClose() { + try { + if (fileOutput != null) { + fileOutput.flush(); + fileOutput.close(); + fileOutput = null; + } + } catch (Exception e) { + logger.log(Level.WARNING, "Got error while closing log file: " + e.getMessage(), e); + } + } + + private void internalPublish(LOGTYPE r) { + // first check to see if new file needed. + // if so, use this.internalRotateNow() to do it + + long now = System.currentTimeMillis(); + if (nextRotationTime <= 0) { + nextRotationTime = getNextRotationTime(now); // lazy initialization + } + if (now > nextRotationTime || fileOutput == null) { + internalRotateNow(); + } + try { + logWriter.write(r, fileOutput); + fileOutput.write('\n'); + } catch (IOException e) { + logger.warning("Failed writing log record: " + Exceptions.toMessageString(e)); + } + } + + /** + * Find next rotation after specified time. + * + * @param now the specified time; if zero, current time is used. + * @return the next rotation time + */ + long getNextRotationTime(long now) { + if (now <= 0) { + now = System.currentTimeMillis(); + } + long nowTod = timeOfDayMillis(now); + long next = 0; + for (long rotationTime : rotationTimes) { + if (nowTod < rotationTime) { + next = rotationTime - nowTod + now; + break; + } + } + if (next == 0) { // didn't find one -- use 1st time 'tomorrow' + next = rotationTimes[0] + lengthOfDayMillis - nowTod + now; + } + + return next; + } + + private void checkAndCreateDir(String pathname) { + int lastSlash = pathname.lastIndexOf("/"); + if (lastSlash > -1) { + String pathExcludingFilename = pathname.substring(0, lastSlash); + File filepath = new File(pathExcludingFilename); + if (!filepath.exists()) { + filepath.mkdirs(); + } + } + } + + + // Throw InterruptedException upwards rather than relying on isInterrupted to stop the thread as + // isInterrupted() returns false after interruption in p.waitFor + private void internalRotateNow() { + // figure out new file name, then + + String oldFileName = fileName; + long now = System.currentTimeMillis(); + fileName = LogFormatter.insertDate(filePattern, now); + internalClose(); + try { + checkAndCreateDir(fileName); + fileOutput = new PageCacheFriendlyFileOutputStream(nativeIO, Paths.get(fileName), 4 * 1024 * 1024); + LogFileDb.nowLoggingTo(fileName); + } catch (IOException e) { + throw new RuntimeException("Couldn't open log file '" + fileName + "'", e); + } + + if(oldFileName == null) oldFileName = getOldFileNameFromSymlink(); // To compress previous file, if so configured + createSymlinkToCurrentFile(); + + nextRotationTime = 0; //figure it out later (lazy evaluation) + if ((oldFileName != null)) { + Path oldFile = Paths.get(oldFileName); + if (Files.exists(oldFile)) { + executor.execute(() -> runCompression(nativeIO, oldFile, compression)); + } + } + } + + + private static void runCompression(NativeIO nativeIO, Path oldFile, Compression compression) { + switch (compression) { + case ZSTD: + runCompressionZstd(nativeIO, oldFile); + break; + case GZIP: + runCompressionGzip(nativeIO, oldFile); + break; + case NONE: + runCompressionNone(nativeIO, oldFile); + break; + default: + throw new IllegalArgumentException("Unknown compression " + compression); + } + } + + private static void runCompressionNone(NativeIO nativeIO, Path oldFile) { + nativeIO.dropFileFromCache(oldFile.toFile()); + } + + private static void runCompressionZstd(NativeIO nativeIO, Path oldFile) { + try { + Path compressedFile = Paths.get(oldFile.toString() + ".zst"); + int bufferSize = 2*1024*1024; + try (FileOutputStream fileOut = AtomicFileOutputStream.create(compressedFile); + ZstdOuputStream out = new ZstdOuputStream(fileOut, bufferSize); + FileInputStream in = new FileInputStream(oldFile.toFile())) { + pageFriendlyTransfer(nativeIO, out, fileOut.getFD(), in, bufferSize); + out.flush(); + } + Files.delete(oldFile); + nativeIO.dropFileFromCache(compressedFile.toFile()); + } catch (IOException e) { + logger.log(Level.WARNING, "Failed to compress log file with zstd: " + oldFile, e); + } finally { + nativeIO.dropFileFromCache(oldFile.toFile()); + } + } + + private static void runCompressionGzip(NativeIO nativeIO, Path oldFile) { + try { + Path gzippedFile = Paths.get(oldFile.toString() + ".gz"); + try (FileOutputStream fileOut = AtomicFileOutputStream.create(gzippedFile); + GZIPOutputStream compressor = new GZIPOutputStream(fileOut, 0x100000); + FileInputStream inputStream = new FileInputStream(oldFile.toFile())) { + pageFriendlyTransfer(nativeIO, compressor, fileOut.getFD(), inputStream, 0x400000); + compressor.finish(); + compressor.flush(); + } + Files.delete(oldFile); + nativeIO.dropFileFromCache(gzippedFile.toFile()); + } catch (IOException e) { + logger.log(Level.WARNING, "Failed to compress log file with gzip: " + oldFile, e); + } finally { + nativeIO.dropFileFromCache(oldFile.toFile()); + } + } + + private static void pageFriendlyTransfer(NativeIO nativeIO, OutputStream out, FileDescriptor outDescriptor, FileInputStream in, int bufferSize) throws IOException { + int read; + long totalBytesRead = 0; + byte[] buffer = new byte[bufferSize]; + while ((read = in.read(buffer)) >= 0) { + out.write(buffer, 0, read); + if (read > 0) { + nativeIO.dropPartialFileFromCache(in.getFD(), totalBytesRead, read, false); + nativeIO.dropPartialFileFromCache(outDescriptor, totalBytesRead, read, false); + } + totalBytesRead += read; + } + } + + /** + * Name files by date - create a symlink with a constant name to the newest file + */ + private void createSymlinkToCurrentFile() { + if (symlinkName == null) return; + Path target = Paths.get(fileName); + Path link = target.resolveSibling(symlinkName); + try { + Files.deleteIfExists(link); + Files.createSymbolicLink(link, target.getFileName()); + } catch (IOException e) { + logger.log(Level.WARNING, "Failed to create symbolic link to current log file: " + e.getMessage(), e); + } + } + + private String getOldFileNameFromSymlink() { + if(symlinkName == null) return null; + try { + return Paths.get(fileName).resolveSibling(symlinkName).toRealPath().toString(); + } catch (IOException e) { + return null; + } + } + + private static final long lengthOfDayMillis = 24 * 60 * 60 * 1000; + private static long timeOfDayMillis(long time) { + return time % lengthOfDayMillis; + } + + } + + private static class Operation<LOGTYPE> { + enum Type {log, flush, close, rotate} + + final Type type; + + final Optional<LOGTYPE> log; + final CountDownLatch countDownLatch = new CountDownLatch(1); + + Operation(Type type) { + this(type, Optional.empty()); + } + + Operation(LOGTYPE log) { + this(Type.log, Optional.of(log)); + } + + private Operation(Type type, Optional<LOGTYPE> log) { + this.type = type; + this.log = log; + } + } + + /** File output stream that signals to kernel to drop previous pages after write */ + private static class PageCacheFriendlyFileOutputStream extends OutputStream { + + private final NativeIO nativeIO; + private final FileOutputStream fileOut; + private final BufferedOutputStream bufferedOut; + private final int bufferSize; + private long lastDropPosition = 0; + + PageCacheFriendlyFileOutputStream(NativeIO nativeIO, Path file, int bufferSize) throws FileNotFoundException { + this.nativeIO = nativeIO; + this.fileOut = new FileOutputStream(file.toFile(), true); + this.bufferedOut = new BufferedOutputStream(fileOut, bufferSize); + this.bufferSize = bufferSize; + } + + @Override public void write(byte[] b) throws IOException { bufferedOut.write(b); } + @Override public void write(byte[] b, int off, int len) throws IOException { bufferedOut.write(b, off, len); } + @Override public void write(int b) throws IOException { bufferedOut.write(b); } + @Override public void close() throws IOException { bufferedOut.close(); } + + @Override + public void flush() throws IOException { + bufferedOut.flush(); + long newPos = fileOut.getChannel().position(); + if (newPos >= lastDropPosition + bufferSize) { + nativeIO.dropPartialFileFromCache(fileOut.getFD(), lastDropPosition, newPos, true); + lastDropPosition = newPos; + } + } + } + + private static class AtomicFileOutputStream extends FileOutputStream { + private final Path path; + private final Path tmpPath; + private volatile boolean closed = false; + + private AtomicFileOutputStream(Path path, Path tmpPath) throws FileNotFoundException { + super(tmpPath.toFile()); + this.path = path; + this.tmpPath = tmpPath; + } + + @Override + public synchronized void close() throws IOException { + super.close(); + if (!closed) { + Files.move(tmpPath, path, StandardCopyOption.ATOMIC_MOVE); + closed = true; + } + } + + private static AtomicFileOutputStream create(Path path) throws FileNotFoundException { + return new AtomicFileOutputStream(path, path.resolveSibling("." + path.getFileName() + ".tmp")); + } + } +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/LogFormatter.java b/container-core/src/main/java/com/yahoo/container/logging/LogFormatter.java new file mode 100644 index 00000000000..cc1dcb579aa --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/LogFormatter.java @@ -0,0 +1,191 @@ +// Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +import java.text.DateFormat; +import java.text.SimpleDateFormat; +import java.util.Date; +import java.util.Locale; +import java.util.TimeZone; +import java.util.logging.Formatter; +import java.util.logging.LogRecord; + + +/** + * Produces compact output format for prelude logs + * + * @author Bob Travis + */ +public class LogFormatter extends Formatter { + + /** date format objects */ + static SimpleDateFormat ddMMMyyyy; + static DateFormat dfMMM; + static SimpleDateFormat yyyyMMdd; + + static { + ddMMMyyyy = new SimpleDateFormat("[dd/MMM/yyyy:HH:mm:ss Z]", Locale.US); + ddMMMyyyy.setTimeZone(TimeZone.getTimeZone("UTC")); + + dfMMM = new SimpleDateFormat("MMM", Locale.US); + dfMMM.setTimeZone(TimeZone.getTimeZone("UTC")); + + yyyyMMdd = new SimpleDateFormat("[yyyy-MM-dd HH:mm:ss]", Locale.US); + yyyyMMdd.setTimeZone(TimeZone.getTimeZone("UTC")); + } + + /** Whether to strip down the message to only the message or not */ + private boolean messageOnly = false; + + /** Controls which of the available timestamp formats is used in all log records + */ + private static final int timestampFormat = 2; // 0=millis, 1=mm/dd/yyyy, 2=yyyy-mm-dd + + /** + * Standard constructor + */ + + public LogFormatter() {} + + /** + * Make it possible to log stripped messages + */ + public void messageOnly (boolean messageOnly) { + this.messageOnly = messageOnly; + } + + public String format(LogRecord record) { + + // if we don't want any other stuff we just return the message + if (messageOnly) { + return formatMessage(record); + } + + String rawMsg = record.getMessage(); + boolean isLogMsg = + rawMsg.charAt(0) == 'L' + && rawMsg.charAt(1) == 'O' + && rawMsg.charAt(2) == 'G' + && rawMsg.charAt(3) == ':'; + String nameInsert = + (!isLogMsg) + ? record.getLevel().getName() + ": " + : ""; + return (timeStamp(record) + + nameInsert + + formatMessage(record) + + "\n" + ); + } + + /** + * Public support methods + */ + + /** + * Static insertDate method will insert date fragments into a string + * based on '%x' pattern elements. Equivalents in SimpleDateFormatter patterns, + * with examples: + * <ul> + * <li>%Y YYYY 2003 + * <li>%m MM 08 + * <li>%x MMM Aug + * <li>%d dd 25 + * <li>%H HH 14 + * <li>%M mm 30 + * <li>%S ss 35 + * <li>%s SSS 123 + * <li>%Z Z -0400 + * </ul> + *Others: + * <ul> + * <li>%T Long.toString(time) + * <li>%% % + * </ul> + */ + public static String insertDate(String pattern, long time) { + DateFormat df = new SimpleDateFormat("yyyy.MM.dd:HH:mm:ss.SSS Z", Locale.US); + df.setTimeZone(TimeZone.getTimeZone("UTC")); + Date date = new Date(time); + String datetime = df.format(date); + StringBuilder result = new StringBuilder(); + int i=0; + while (i < pattern.length()) { + int j = pattern.indexOf('%',i); + if (j == -1 || j >= pattern.length()-1) { // done + result.append(pattern.substring(i)); // copy rest of pattern and quit + break; + } + result.append(pattern.substring(i, j)); + switch (pattern.charAt(j+1)) { + case 'Y': + result.append(datetime.substring(0,4)); // year + break; + case 'm': + result.append(datetime.substring(5,7)); // month + break; + case 'd': + result.append(datetime.substring(8,10)); // day of month + break; + case 'H': + result.append(datetime.substring(11,13)); // hour + break; + case 'M': + result.append(datetime.substring(14,16)); // minute + break; + case 'S': + result.append(datetime.substring(17,19)); // second + break; + case 's': + result.append(datetime.substring(20,23)); // thousanths + break; + case 'Z': + result.append(datetime.substring(24)); // time zone string + break; + case 'T': + result.append(Long.toString(time)); //time in Millis + break; + case 'x': + result.append(capitalize(dfMMM.format(date))); + break; + case '%': + result.append("%%"); + break; + default: + result.append("%"); // copy pattern escape and move on + j--; // only want to bump by one position.... + break; + } + i = j+2; + } + + return result.toString(); + } + + /** + * Private methods: timeStamp(LogRecord) + */ + private String timeStamp(LogRecord record) { + Date date = new Date(record.getMillis()); + String stamp; + switch (timestampFormat) { + case 0: + stamp = Long.toString(record.getMillis()); + break; + case 1: + stamp = ddMMMyyyy.format(date); + break; + case 2: + default: + stamp = yyyyMMdd.format(date); + break; + } + return stamp; + } + + /** Return the given string with the first letter in upper case */ + private static String capitalize(String string) { + if (Character.isUpperCase(string.charAt(0))) return string; + return Character.toUpperCase(string.charAt(0)) + string.substring(1); + } + +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/LogWriter.java b/container-core/src/main/java/com/yahoo/container/logging/LogWriter.java new file mode 100644 index 00000000000..15a983cfb43 --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/LogWriter.java @@ -0,0 +1,10 @@ +// Copyright Verizon Media. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. + +package com.yahoo.container.logging; + +import java.io.IOException; +import java.io.OutputStream; + +interface LogWriter <LOGTYPE> { + void write(LOGTYPE record, OutputStream outputStream) throws IOException; +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/RequestLog.java b/container-core/src/main/java/com/yahoo/container/logging/RequestLog.java new file mode 100644 index 00000000000..2090ba1b9f1 --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/RequestLog.java @@ -0,0 +1,13 @@ +// Copyright Verizon Media. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +/** + * Access logging for requests + * + * @author bjorncs + */ +public interface RequestLog { + + void log(RequestLogEntry entry); + +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/RequestLogEntry.java b/container-core/src/main/java/com/yahoo/container/logging/RequestLogEntry.java new file mode 100644 index 00000000000..819907fc9f1 --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/RequestLogEntry.java @@ -0,0 +1,186 @@ +// Copyright Verizon Media. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +import com.yahoo.yolean.trace.TraceNode; + +import java.security.Principal; +import java.time.Duration; +import java.time.Instant; +import java.util.ArrayList; +import java.util.Collection; +import java.util.Collections; +import java.util.HashMap; +import java.util.Map; +import java.util.Optional; +import java.util.OptionalInt; +import java.util.OptionalLong; + +import static java.util.Objects.requireNonNull; + +/** + * A immutable request log entry + * + * @author bjorncs + */ +public class RequestLogEntry { + + private final String connectionId; + private final Instant timestamp; + private final Duration duration; + private final int localPort; + private final String peerAddress; + private final int peerPort; + private final String remoteAddress; + private final int remotePort; + private final String userAgent; + private final String referer; + private final String httpMethod; + private final String httpVersion; + private final String hostString; + private final int statusCode; + private final long contentSize; + private final String scheme; + private final String rawPath; + private final String rawQuery; + private final Principal userPrincipal; + private final Principal sslPrincipal; + private final HitCounts hitCounts; + private final TraceNode traceNode; + private final Map<String, Collection<String>> extraAttributes; + + private RequestLogEntry(Builder builder) { + this.connectionId = builder.connectionId; + this.timestamp = builder.timestamp; + this.duration = builder.duration; + this.localPort = builder.localPort; + this.peerAddress = builder.peerAddress; + this.peerPort = builder.peerPort; + this.remoteAddress = builder.remoteAddress; + this.remotePort = builder.remotePort; + this.userAgent = builder.userAgent; + this.referer = builder.referer; + this.httpMethod = builder.httpMethod; + this.httpVersion = builder.httpVersion; + this.hostString = builder.hostString; + this.statusCode = builder.statusCode; + this.contentSize = builder.contentSize; + this.scheme = builder.scheme; + this.rawPath = builder.rawPath; + this.rawQuery = builder.rawQuery; + this.userPrincipal = builder.userPrincipal; + this.sslPrincipal = builder.sslPrincipal; + this.hitCounts = builder.hitCounts; + this.traceNode = builder.traceNode; + this.extraAttributes = copyExtraAttributes(builder.extraAttributes); + } + + public Optional<String> connectionId() { return Optional.ofNullable(connectionId); } + public Optional<Instant> timestamp() { return Optional.ofNullable(timestamp); } + public Optional<Duration> duration() { return Optional.ofNullable(duration); } + public OptionalInt localPort() { return optionalInt(localPort); } + public Optional<String> peerAddress() { return Optional.ofNullable(peerAddress); } + public OptionalInt peerPort() { return optionalInt(peerPort); } + public Optional<String> remoteAddress() { return Optional.ofNullable(remoteAddress); } + public OptionalInt remotePort() { return optionalInt(remotePort); } + public Optional<String> userAgent() { return Optional.ofNullable(userAgent); } + public Optional<String> referer() { return Optional.ofNullable(referer); } + public Optional<String> httpMethod() { return Optional.ofNullable(httpMethod); } + public Optional<String> httpVersion() { return Optional.ofNullable(httpVersion); } + public Optional<String> hostString() { return Optional.ofNullable(hostString); } + public OptionalInt statusCode() { return optionalInt(statusCode); } + public OptionalLong contentSize() { return optionalLong(contentSize); } + public Optional<String> scheme() { return Optional.ofNullable(scheme); } + public Optional<String> rawPath() { return Optional.ofNullable(rawPath); } + public Optional<String> rawQuery() { return Optional.ofNullable(rawQuery); } + public Optional<Principal> userPrincipal() { return Optional.ofNullable(userPrincipal); } + public Optional<Principal> sslPrincipal() { return Optional.ofNullable(sslPrincipal); } + public Optional<HitCounts> hitCounts() { return Optional.ofNullable(hitCounts); } + public Optional<TraceNode> traceNode() { return Optional.ofNullable(traceNode); } + public Collection<String> extraAttributeKeys() { return Collections.unmodifiableCollection(extraAttributes.keySet()); } + public Collection<String> extraAttributeValues(String key) { return Collections.unmodifiableCollection(extraAttributes.get(key)); } + + private static OptionalInt optionalInt(int value) { + if (value == -1) return OptionalInt.empty(); + return OptionalInt.of(value); + } + + private static OptionalLong optionalLong(long value) { + if (value == -1) return OptionalLong.empty(); + return OptionalLong.of(value); + } + + private static Map<String, Collection<String>> copyExtraAttributes(Map<String, Collection<String>> extraAttributes) { + Map<String, Collection<String>> copy = new HashMap<>(); + extraAttributes.forEach((key, value) -> copy.put(key, new ArrayList<>(value))); + return copy; + } + + public static class Builder { + + private String connectionId; + private Instant timestamp; + private Duration duration; + private int localPort = -1; + private String peerAddress; + private int peerPort = -1; + private String remoteAddress; + private int remotePort = -1; + private String userAgent; + private String referer; + private String httpMethod; + private String httpVersion; + private String hostString; + private int statusCode = -1; + private long contentSize = -1; + private String scheme; + private String rawPath; + private String rawQuery; + private Principal userPrincipal; + private HitCounts hitCounts; + private TraceNode traceNode; + private Principal sslPrincipal; + private final Map<String, Collection<String>> extraAttributes = new HashMap<>(); + + public Builder connectionId(String connectionId) { this.connectionId = requireNonNull(connectionId); return this; } + public Builder timestamp(Instant timestamp) { this.timestamp = requireNonNull(timestamp); return this; } + public Builder duration(Duration duration) { this.duration = requireNonNull(duration); return this; } + public Builder localPort(int localPort) { this.localPort = requireNonNegative(localPort); return this; } + public Builder peerAddress(String peerAddress) { this.peerAddress = requireNonNull(peerAddress); return this; } + public Builder peerPort(int peerPort) { this.peerPort = requireNonNegative(peerPort); return this; } + public Builder remoteAddress(String remoteAddress) { this.remoteAddress = requireNonNull(remoteAddress); return this; } + public Builder remotePort(int remotePort) { this.remotePort = requireNonNegative(remotePort); return this; } + public Builder userAgent(String userAgent) { this.userAgent = requireNonNull(userAgent); return this; } + public Builder referer(String referer) { this.referer = requireNonNull(referer); return this; } + public Builder httpMethod(String httpMethod) { this.httpMethod = requireNonNull(httpMethod); return this; } + public Builder httpVersion(String httpVersion) { this.httpVersion = requireNonNull(httpVersion); return this; } + public Builder hostString(String hostString) { this.hostString = requireNonNull(hostString); return this; } + public Builder statusCode(int statusCode) { this.statusCode = requireNonNegative(statusCode); return this; } + public Builder contentSize(long contentSize) { this.contentSize = requireNonNegative(contentSize); return this; } + public Builder scheme(String scheme) { this.scheme = requireNonNull(scheme); return this; } + public Builder rawPath(String rawPath) { this.rawPath = requireNonNull(rawPath); return this; } + public Builder rawQuery(String rawQuery) { this.rawQuery = requireNonNull(rawQuery); return this; } + public Builder userPrincipal(Principal userPrincipal) { this.userPrincipal = requireNonNull(userPrincipal); return this; } + public Builder sslPrincipal(Principal sslPrincipal) { this.sslPrincipal = requireNonNull(sslPrincipal); return this; } + public Builder hitCounts(HitCounts hitCounts) { this.hitCounts = requireNonNull(hitCounts); return this; } + public Builder traceNode(TraceNode traceNode) { this.traceNode = requireNonNull(traceNode); return this; } + public Builder addExtraAttribute(String key, String value) { + this.extraAttributes.computeIfAbsent(requireNonNull(key), __ -> new ArrayList<>()).add(requireNonNull(value)); + return this; + } + public Builder addExtraAttributes(String key, Collection<String> values) { + this.extraAttributes.computeIfAbsent(requireNonNull(key), __ -> new ArrayList<>()).addAll(requireNonNull(values)); + return this; + } + public RequestLogEntry build() { return new RequestLogEntry(this); } + + private static int requireNonNegative(int value) { + if (value < 0) throw new IllegalArgumentException("Value must be non-negative: " + value); + return value; + } + + private static long requireNonNegative(long value) { + if (value < 0) throw new IllegalArgumentException("Value must be non-negative: " + value); + return value; + } + } +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/RequestLogHandler.java b/container-core/src/main/java/com/yahoo/container/logging/RequestLogHandler.java new file mode 100644 index 00000000000..85df08e4abb --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/RequestLogHandler.java @@ -0,0 +1,9 @@ +// Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +/** + * @author Tony Vaagenes + */ +public interface RequestLogHandler { + void log(RequestLogEntry entry); +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/TraceRenderer.java b/container-core/src/main/java/com/yahoo/container/logging/TraceRenderer.java new file mode 100644 index 00000000000..41b88e08c19 --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/TraceRenderer.java @@ -0,0 +1,186 @@ +// Copyright Verizon Media. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +import com.yahoo.data.access.Inspectable; +import com.yahoo.data.access.Inspector; +import com.yahoo.data.access.simple.JsonRender; +import com.yahoo.yolean.trace.TraceNode; +import com.yahoo.yolean.trace.TraceVisitor; +import com.fasterxml.jackson.core.JsonGenerator; + +import java.io.IOException; + +public class TraceRenderer extends TraceVisitor { + private static final String TRACE_CHILDREN = "children"; + private static final String TRACE_MESSAGE = "message"; + private static final String TRACE_TIMESTAMP = "timestamp"; + private static final String TRACE = "trace"; + + private final long basetime; + private final JsonGenerator generator; + private final FieldConsumer fieldConsumer; + private boolean hasFieldName = false; + int emittedChildNesting = 0; + int currentChildNesting = 0; + private boolean insideOpenObject = false; + + public interface FieldConsumer { + void accept(Object object) throws IOException; + } + + private static class Consumer implements FieldConsumer { + private final JsonGenerator generator; + + Consumer(JsonGenerator generator) { + this.generator = generator; + } + + @Override + public void accept(Object object) throws IOException { + if (object instanceof Inspectable) { + renderInspectorDirect(((Inspectable) object).inspect()); + } else { + generator.writeObject(object); + } + } + private void renderInspectorDirect(Inspector data) throws IOException { + StringBuilder intermediate = new StringBuilder(); + JsonRender.render(data, intermediate, true); + generator.writeRawValue(intermediate.toString()); + } + } + + TraceRenderer(JsonGenerator generator, long basetime) { + this(generator, new Consumer(generator), basetime); + } + public TraceRenderer(JsonGenerator generator, FieldConsumer consumer, long basetime) { + this.generator = generator; + this.fieldConsumer = consumer; + this.basetime = basetime; + } + + @Override + public void entering(TraceNode node) { + ++currentChildNesting; + } + + @Override + public void leaving(TraceNode node) { + conditionalEndObject(); + if (currentChildNesting == emittedChildNesting) { + try { + generator.writeEndArray(); + generator.writeEndObject(); + } catch (IOException e) { + throw new TraceRenderWrapper(e); + } + --emittedChildNesting; + } + --currentChildNesting; + } + + @Override + public void visit(TraceNode node) { + try { + doVisit(node.timestamp(), node.payload(), node.children().iterator().hasNext()); + } catch (IOException e) { + throw new TraceRenderWrapper(e); + } + } + + private void doVisit(long timestamp, Object payload, boolean hasChildren) throws IOException { + boolean dirty = false; + if (timestamp != 0L) { + header(); + generator.writeStartObject(); + generator.writeNumberField(TRACE_TIMESTAMP, timestamp - basetime); + dirty = true; + } + if (payload != null) { + if (!dirty) { + header(); + generator.writeStartObject(); + } + generator.writeFieldName(TRACE_MESSAGE); + fieldConsumer.accept(payload); + dirty = true; + } + if (dirty) { + if (!hasChildren) { + generator.writeEndObject(); + } else { + setInsideOpenObject(true); + } + } + } + private void header() { + fieldName(); + for (int i = 0; i < (currentChildNesting - emittedChildNesting); ++i) { + startChildArray(); + } + emittedChildNesting = currentChildNesting; + } + + private void startChildArray() { + try { + conditionalStartObject(); + generator.writeArrayFieldStart(TRACE_CHILDREN); + } catch (IOException e) { + throw new TraceRenderWrapper(e); + } + } + + private void conditionalStartObject() throws IOException { + if (!isInsideOpenObject()) { + generator.writeStartObject(); + } else { + setInsideOpenObject(false); + } + } + + private void conditionalEndObject() { + if (isInsideOpenObject()) { + // This triggers if we were inside a data node with payload and + // subnodes, but none of the subnodes contained data + try { + generator.writeEndObject(); + setInsideOpenObject(false); + } catch (IOException e) { + throw new TraceRenderWrapper(e); + } + } + } + + private void fieldName() { + if (hasFieldName) { + return; + } + + try { + generator.writeFieldName(TRACE); + } catch (IOException e) { + throw new TraceRenderWrapper(e); + } + hasFieldName = true; + } + + boolean isInsideOpenObject() { + return insideOpenObject; + } + + void setInsideOpenObject(boolean insideOpenObject) { + this.insideOpenObject = insideOpenObject; + } + public static final class TraceRenderWrapper extends RuntimeException { + + /** + * Should never be serialized, but this is still needed. + */ + private static final long serialVersionUID = 2L; + + TraceRenderWrapper(IOException wrapped) { + super(wrapped); + } + + } +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/VespaAccessLog.java b/container-core/src/main/java/com/yahoo/container/logging/VespaAccessLog.java new file mode 100644 index 00000000000..254b7fe5385 --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/VespaAccessLog.java @@ -0,0 +1,113 @@ +// Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +import com.yahoo.component.AbstractComponent; +import com.yahoo.container.core.AccessLogConfig; + +import java.io.IOException; +import java.io.OutputStream; +import java.nio.charset.StandardCharsets; +import java.text.SimpleDateFormat; +import java.util.Date; +import java.util.TimeZone; + +/** + * @author Bjorn Borud + * @author Oyvind Bakksjo + */ +public final class VespaAccessLog extends AbstractComponent implements RequestLogHandler, LogWriter<RequestLogEntry> { + + private static final ThreadLocal<SimpleDateFormat> dateFormat = ThreadLocal.withInitial(VespaAccessLog::createDateFormat); + + private final AccessLogHandler logHandler; + + public VespaAccessLog(AccessLogConfig config) { + logHandler = new AccessLogHandler(config.fileHandler(), this); + } + + private static SimpleDateFormat createDateFormat() { + SimpleDateFormat format = new SimpleDateFormat("[dd/MMM/yyyy:HH:mm:ss Z]"); + format.setTimeZone(TimeZone.getTimeZone("UTC")); + return format; + } + + private static String getDate() { + return dateFormat.get().format(new Date()); + } + + private String getRequest(final String httpMethod, final String rawPath, final String rawQuery, final String httpVersion) { + return httpMethod + " " + (rawQuery != null ? rawPath + "?" + rawQuery : rawPath) + " " + httpVersion; + } + + private String getUser(String user) { + return (user == null) ? "-" : user; + } + + private String toLogline(String ipAddr, String user, String request, String referer, String agent, + long durationMillis, long byteCount, HitCounts hitcounts, int returnCode) + { + long ms = Math.max(0L, durationMillis); + StringBuilder sb = new StringBuilder() + .append(ipAddr) + .append(" - ") + .append(getUser(user)) + .append(' ') + .append(getDate()) + .append(" \"") + .append(request) + .append("\" ") + .append(returnCode) + .append(' ') + .append(byteCount) + .append(" \"") + .append(referer) + .append("\" \"") + .append(agent) + .append("\" ") + .append(ms/1000) + .append('.'); + decimalsOfSecondsFromMilliseconds(ms, sb); + sb.append(' ') + .append((hitcounts == null) ? 0 : hitcounts.getTotalHitCount()) + .append(" 0.0 ") + .append((hitcounts == null) ? 0 : hitcounts.getSummaryCount()); + return sb.toString(); + } + + private void decimalsOfSecondsFromMilliseconds(long ms, StringBuilder sb) { + long dec = ms % 1000; + String numbers = String.valueOf(dec); + if (dec <= 9) { + sb.append("00"); + } else if (dec <= 99) { + sb.append('0'); + } + sb.append(numbers); + } + + @Override public void deconstruct() { logHandler.shutdown(); } + + @Override + public void log(RequestLogEntry entry) { + logHandler.log(entry); + } + + @Override + public void write(RequestLogEntry entry, OutputStream outputStream) throws IOException { + outputStream.write( + toLogline( + entry.peerAddress().get(), + null, + getRequest( + entry.httpMethod().orElse(null), + entry.rawPath().orElse(null), + entry.rawQuery().orElse(null), + entry.httpVersion().orElse(null)), + entry.referer().orElse(null), + entry.userAgent().orElse(null), + entry.duration().get().toMillis(), + entry.contentSize().orElse(0L), + entry.hitCounts().orElse(null), + entry.statusCode().orElse(0)).getBytes(StandardCharsets.UTF_8)); + } +} diff --git a/container-core/src/main/java/com/yahoo/container/logging/package-info.java b/container-core/src/main/java/com/yahoo/container/logging/package-info.java new file mode 100644 index 00000000000..fc2abb7b609 --- /dev/null +++ b/container-core/src/main/java/com/yahoo/container/logging/package-info.java @@ -0,0 +1,5 @@ +// Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +@ExportPackage +package com.yahoo.container.logging; + +import com.yahoo.osgi.annotation.ExportPackage; |