summaryrefslogtreecommitdiffstats
path: root/jdisc_http_service
diff options
context:
space:
mode:
authorBjørn Christian Seime <bjorncs@verizonmedia.com>2021-01-11 14:27:21 +0100
committerBjørn Christian Seime <bjorncs@verizonmedia.com>2021-01-11 14:27:21 +0100
commit2cd1396c51252b36cb14dfb622e8153ff59cd92d (patch)
treea7a6a14aa7d83136f5484ce4b6c345fc9246b19c /jdisc_http_service
parentd9db41186c2732dbb3eec3d0259a6020adc75b48 (diff)
Merge container-accesslogging into jdisc_http_service
Diffstat (limited to 'jdisc_http_service')
-rw-r--r--jdisc_http_service/pom.xml12
-rw-r--r--jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLog.java32
-rw-r--r--jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLogEntry.java522
-rw-r--r--jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLogHandler.java48
-rw-r--r--jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLogInterface.java9
-rw-r--r--jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLogSampler.java37
-rw-r--r--jdisc_http_service/src/main/java/com/yahoo/container/logging/CircularArrayAccessLogKeeper.java48
-rw-r--r--jdisc_http_service/src/main/java/com/yahoo/container/logging/Coverage.java64
-rw-r--r--jdisc_http_service/src/main/java/com/yahoo/container/logging/HitCounts.java78
-rw-r--r--jdisc_http_service/src/main/java/com/yahoo/container/logging/JSONAccessLog.java36
-rw-r--r--jdisc_http_service/src/main/java/com/yahoo/container/logging/JSONFormatter.java221
-rw-r--r--jdisc_http_service/src/main/java/com/yahoo/container/logging/LogFileHandler.java397
-rw-r--r--jdisc_http_service/src/main/java/com/yahoo/container/logging/LogFormatter.java191
-rw-r--r--jdisc_http_service/src/main/java/com/yahoo/container/logging/TraceRenderer.java185
-rw-r--r--jdisc_http_service/src/main/java/com/yahoo/container/logging/VespaAccessLog.java111
-rw-r--r--jdisc_http_service/src/main/java/com/yahoo/container/logging/package-info.java5
-rw-r--r--jdisc_http_service/src/main/resources/configdefinitions/container.core.access-log.def17
-rw-r--r--jdisc_http_service/src/test/java/com/yahoo/container/logging/AccessLogSamplerTest.java62
-rw-r--r--jdisc_http_service/src/test/java/com/yahoo/container/logging/CircularArrayAccessLogKeeperTest.java42
-rw-r--r--jdisc_http_service/src/test/java/com/yahoo/container/logging/CompressWhileDrop.java11
-rw-r--r--jdisc_http_service/src/test/java/com/yahoo/container/logging/JSONLogTestCase.java276
-rw-r--r--jdisc_http_service/src/test/java/com/yahoo/container/logging/LogFileHandlerTestCase.java187
-rw-r--r--jdisc_http_service/src/test/java/com/yahoo/container/logging/test/LogFormatterTestCase.java27
23 files changed, 2615 insertions, 3 deletions
diff --git a/jdisc_http_service/pom.xml b/jdisc_http_service/pom.xml
index 094ca7baa25..4589dbb6a68 100644
--- a/jdisc_http_service/pom.xml
+++ b/jdisc_http_service/pom.xml
@@ -68,23 +68,24 @@
</dependency>
<dependency>
<groupId>com.yahoo.vespa</groupId>
- <artifactId>container-accesslogging</artifactId>
+ <artifactId>security-utils</artifactId>
<version>${project.version}</version>
<scope>provided</scope>
</dependency>
<dependency>
<groupId>com.yahoo.vespa</groupId>
- <artifactId>security-utils</artifactId>
+ <artifactId>yolean</artifactId>
<version>${project.version}</version>
<scope>provided</scope>
</dependency>
<dependency>
<groupId>com.yahoo.vespa</groupId>
- <artifactId>yolean</artifactId>
+ <artifactId>vespalog</artifactId>
<version>${project.version}</version>
<scope>provided</scope>
</dependency>
+
<!-- TEST SCOPE -->
<dependency>
<groupId>org.apache.httpcomponents</groupId>
@@ -127,6 +128,11 @@
<artifactId>bcpkix-jdk15on</artifactId>
<scope>test</scope>
</dependency>
+ <dependency>
+ <groupId>org.assertj</groupId>
+ <artifactId>assertj-core</artifactId>
+ <scope>test</scope>
+ </dependency>
</dependencies>
<build>
<plugins>
diff --git a/jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLog.java b/jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLog.java
new file mode 100644
index 00000000000..5c1a549070c
--- /dev/null
+++ b/jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLog.java
@@ -0,0 +1,32 @@
+// 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
+ */
+public class AccessLog {
+
+ private ComponentRegistry<AccessLogInterface> implementers;
+
+ @Inject
+ public AccessLog(ComponentRegistry<AccessLogInterface> implementers) {
+ this.implementers = implementers;
+ }
+
+ public static AccessLog voidAccessLog() {
+ return new AccessLog(new ComponentRegistry<>());
+ }
+
+ public void log(AccessLogEntry accessLogEntry) {
+ for (AccessLogInterface log: implementers.allComponents()) {
+ log.log(accessLogEntry);
+ }
+ }
+
+}
diff --git a/jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLogEntry.java b/jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLogEntry.java
new file mode 100644
index 00000000000..d8085cc808b
--- /dev/null
+++ b/jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLogEntry.java
@@ -0,0 +1,522 @@
+// 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 javax.security.auth.x500.X500Principal;
+import java.net.InetAddress;
+import java.net.InetSocketAddress;
+import java.security.Principal;
+import java.util.ArrayList;
+import java.util.Collections;
+import java.util.List;
+import java.util.Map;
+import java.util.Optional;
+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 {
+
+ // Sadly, there's no way to do compile-time validation of these field references.
+ private static final String[] FIELDS_EXCLUDED_FROM_TOSTRING = new String[] {
+ "monitor"
+ };
+
+ private final Object monitor = new Object();
+
+ private String ipV4AddressInDotDecimalNotation;
+ private long timeStampMillis;
+ private long durationBetweenRequestResponseMillis;
+ private long numBytesReturned;
+
+ private String remoteAddress;
+ private int remotePort;
+ private String peerAddress;
+ private int peerPort;
+
+ private String profile;
+ private String errorMessage;
+ private String fileName;
+ private String userAgent;
+ private String referer;
+ private String user;
+ private HitCounts hitCounts;
+ private String httpMethod;
+ private String httpVersion;
+ private String hostString;
+ private int statusCode;
+ private String scheme;
+ private int localPort;
+ private Principal principal;
+ private X500Principal sslPrincipal;
+ private String rawPath;
+ private String rawQuery;
+ private TraceNode traceNode;
+
+ private ListMap<String,String> keyValues=null;
+
+ public void setProfile( String profile ) {
+ synchronized (monitor) {
+ requireNull(this.profile);
+ this.profile = profile;
+ }
+ }
+
+ public String getProfile() {
+ synchronized (monitor) {
+ return profile;
+ }
+ }
+
+ public void setErrorMessage(String errorMessage) {
+ synchronized (monitor) {
+ requireNull(this.errorMessage);
+ this.errorMessage = errorMessage;
+ }
+ }
+
+ public String getErrorMessage() {
+ synchronized (monitor) {
+ return errorMessage;
+ }
+ }
+
+ public void setFileName(String fileName) {
+ synchronized (monitor) {
+ requireNull(this.fileName);
+ this.fileName = fileName;
+ }
+ }
+
+ public String getFileName() {
+ synchronized (monitor) {
+ return fileName;
+ }
+ }
+
+ public void setUserAgent(String userAgent) {
+ synchronized (monitor) {
+ requireNull(this.userAgent);
+ this.userAgent = userAgent;
+ }
+ }
+
+ public String getUserAgent() {
+ synchronized (monitor) {
+ return userAgent;
+ }
+ }
+
+ public void setReferer(String referer) {
+ synchronized (monitor) {
+ requireNull(this.referer);
+ this.referer = referer;
+ }
+ }
+
+ public String getReferer() {
+ synchronized (monitor) {
+ return referer;
+ }
+ }
+
+ public void setUser(final String user) {
+ synchronized (monitor) {
+ requireNull(this.user);
+ this.user = user;
+ }
+ }
+
+ public String getUser() {
+ synchronized (monitor) {
+ return user;
+ }
+ }
+
+ 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 enum HttpMethod {
+ GET, POST;
+ }
+
+ public void setHttpMethod(HttpMethod method) {
+ setHttpMethod(method.toString());
+ }
+
+ public void setHttpMethod(String method) {
+ synchronized (monitor) {
+ requireNull(this.httpMethod);
+ this.httpMethod = method;
+ }
+ }
+
+ public String getHttpMethod() {
+ synchronized (monitor) {
+ return httpMethod;
+ }
+ }
+
+ public void setHttpVersion(final String httpVersion) {
+ synchronized (monitor) {
+ requireNull(this.httpVersion);
+ this.httpVersion = httpVersion;
+ }
+ }
+
+ public String getHttpVersion() {
+ synchronized (monitor) {
+ return httpVersion;
+ }
+ }
+
+ public void setHostString(String hostString) {
+ synchronized (monitor) {
+ requireNull(this.hostString);
+ this.hostString = hostString;
+ }
+ }
+
+ public String getHostString() {
+ synchronized (monitor) {
+ return hostString;
+ }
+ }
+
+ public void setIpV4Address(String ipV4AddressInDotDecimalNotation) {
+ synchronized (monitor) {
+ requireNull(this.ipV4AddressInDotDecimalNotation);
+ this.ipV4AddressInDotDecimalNotation = ipV4AddressInDotDecimalNotation;
+ }
+ }
+
+ public String getIpV4Address() {
+ synchronized (monitor) {
+ return ipV4AddressInDotDecimalNotation;
+ }
+ }
+
+ public void setTimeStamp(long numMillisSince1Jan1970AtMidnightUTC) {
+ synchronized (monitor) {
+ requireZero(this.timeStampMillis);
+ timeStampMillis = numMillisSince1Jan1970AtMidnightUTC;
+ }
+ }
+
+ public long getTimeStampMillis() {
+ synchronized (monitor) {
+ return timeStampMillis;
+ }
+ }
+
+ public void setDurationBetweenRequestResponse(long timeInMillis) {
+ synchronized (monitor) {
+ requireZero(this.durationBetweenRequestResponseMillis);
+ durationBetweenRequestResponseMillis = timeInMillis;
+ }
+ }
+
+ public long getDurationBetweenRequestResponseMillis() {
+ synchronized (monitor) {
+ return durationBetweenRequestResponseMillis;
+ }
+ }
+
+ public void setReturnedContentSize(int byteCount) {
+ setReturnedContentSize((long) byteCount);
+ }
+
+ public void setReturnedContentSize(long byteCount) {
+ synchronized (monitor) {
+ requireZero(this.numBytesReturned);
+ numBytesReturned = byteCount;
+ }
+ }
+
+ public long getReturnedContentSize() {
+ synchronized (monitor) {
+ return numBytesReturned;
+ }
+ }
+
+ public void setRemoteAddress(String remoteAddress) {
+ synchronized (monitor) {
+ requireNull(this.remoteAddress);
+ this.remoteAddress = remoteAddress;
+ }
+ }
+
+ public void setRemoteAddress(final InetSocketAddress remoteAddress) {
+ setRemoteAddress(getIpAddressAsString(remoteAddress));
+ }
+
+ private static String getIpAddressAsString(final InetSocketAddress remoteAddress) {
+ final InetAddress inetAddress = remoteAddress.getAddress();
+ if (inetAddress == null) {
+ return null;
+ }
+ return inetAddress.getHostAddress();
+ }
+
+ public String getRemoteAddress() {
+ synchronized (monitor) {
+ return remoteAddress;
+ }
+ }
+
+ public void setRemotePort(int remotePort) {
+ synchronized (monitor) {
+ requireZero(this.remotePort);
+ this.remotePort = remotePort;
+ }
+ }
+
+ public int getRemotePort() {
+ synchronized (monitor) {
+ return remotePort;
+ }
+ }
+
+ public void setPeerAddress(final String peerAddress) {
+ synchronized (monitor) {
+ requireNull(this.peerAddress);
+ this.peerAddress = peerAddress;
+ }
+ }
+
+ public void setPeerPort(int peerPort) {
+ synchronized (monitor) {
+ requireZero(this.peerPort);
+ this.peerPort = peerPort;
+ }
+ }
+
+ public int getPeerPort() {
+ synchronized (monitor) {
+ return peerPort;
+ }
+ }
+
+ public String getPeerAddress() {
+ synchronized (monitor) {
+ return peerAddress;
+ }
+ }
+
+ public void setStatusCode(int statusCode) {
+ synchronized (monitor) {
+ requireZero(this.statusCode);
+ this.statusCode = statusCode;
+ }
+ }
+
+ public int getStatusCode() {
+ synchronized (monitor) {
+ return statusCode;
+ }
+ }
+
+ public String getScheme() {
+ synchronized (monitor) {
+ return scheme;
+ }
+ }
+
+ public void setScheme(String scheme) {
+ synchronized (monitor) {
+ requireNull(this.scheme);
+ this.scheme = scheme;
+ }
+ }
+
+ public int getLocalPort() {
+ synchronized (monitor) {
+ return localPort;
+ }
+ }
+
+ public void setLocalPort(int localPort) {
+ synchronized (monitor) {
+ requireZero(this.localPort);
+ this.localPort = localPort;
+ }
+ }
+
+ public Principal getUserPrincipal() {
+ synchronized (monitor) {
+ return principal;
+ }
+ }
+
+ public void setUserPrincipal(Principal principal) {
+ synchronized (monitor) {
+ requireNull(this.principal);
+ this.principal = principal;
+ }
+ }
+
+ public Principal getSslPrincipal() {
+ synchronized (monitor) {
+ return sslPrincipal;
+ }
+ }
+
+ public void setSslPrincipal(X500Principal sslPrincipal) {
+ synchronized (monitor) {
+ requireNull(this.sslPrincipal);
+ this.sslPrincipal = sslPrincipal;
+ }
+ }
+
+ public void setRawPath(String rawPath) {
+ synchronized (monitor) {
+ requireNull(this.rawPath);
+ this.rawPath = rawPath;
+ }
+ }
+
+ public String getRawPath() {
+ synchronized (monitor) {
+ return rawPath;
+ }
+ }
+
+ public void setRawQuery(String rawQuery) {
+ synchronized (monitor) {
+ requireNull(this.rawQuery);
+ this.rawQuery = rawQuery;
+ }
+ }
+
+ public Optional<String> getRawQuery() {
+ synchronized (monitor) {
+ return Optional.ofNullable(rawQuery);
+ }
+ }
+
+ public void setTrace(TraceNode traceNode) {
+ synchronized (monitor) {
+ requireNull(this.traceNode);
+ this.traceNode = traceNode;
+ }
+ }
+ public TraceNode getTrace() {
+ synchronized (monitor) {
+ return traceNode;
+ }
+ }
+
+ @Override
+ public String toString() {
+ synchronized (monitor) {
+ return "AccessLogEntry{" +
+ "ipV4AddressInDotDecimalNotation='" + ipV4AddressInDotDecimalNotation + '\'' +
+ ", timeStampMillis=" + timeStampMillis +
+ ", durationBetweenRequestResponseMillis=" + durationBetweenRequestResponseMillis +
+ ", numBytesReturned=" + numBytesReturned +
+ ", remoteAddress='" + remoteAddress + '\'' +
+ ", remotePort=" + remotePort +
+ ", peerAddress='" + peerAddress + '\'' +
+ ", peerPort=" + peerPort +
+ ", profile='" + profile + '\'' +
+ ", errorMessage='" + errorMessage + '\'' +
+ ", fileName='" + fileName + '\'' +
+ ", userAgent='" + userAgent + '\'' +
+ ", referer='" + referer + '\'' +
+ ", user='" + user + '\'' +
+ ", hitCounts=" + hitCounts +
+ ", httpMethod='" + httpMethod + '\'' +
+ ", httpVersion='" + httpVersion + '\'' +
+ ", hostString='" + hostString + '\'' +
+ ", statusCode=" + statusCode +
+ ", scheme='" + scheme + '\'' +
+ ", localPort=" + localPort +
+ ", principal=" + principal +
+ ", sslPrincipal=" + sslPrincipal +
+ ", rawPath='" + rawPath + '\'' +
+ ", rawQuery='" + rawQuery + '\'' +
+ ", trace='" + 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);
+ }
+ }
+
+ private static void requireZero(final long value) {
+ if (value != 0) {
+ throw new IllegalStateException("Attempt to overwrite field that has been assigned. Value: " + value);
+ }
+ }
+
+ private static void requireZero(final int value) {
+ if (value != 0) {
+ throw new IllegalStateException("Attempt to overwrite field that has been assigned. Value: " + value);
+ }
+ }
+
+}
diff --git a/jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLogHandler.java b/jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLogHandler.java
new file mode 100644
index 00000000000..488a6137cc2
--- /dev/null
+++ b/jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLogHandler.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 com.yahoo.container.core.AccessLogConfig;
+
+import java.util.logging.Logger;
+
+/**
+ * @author Bjorn Borud
+ */
+class AccessLogHandler {
+
+ public Logger access = Logger.getAnonymousLogger();
+ private LogFileHandler logFileHandler;
+
+ public AccessLogHandler(AccessLogConfig.FileHandler config) {
+ access.setUseParentHandlers(false);
+
+ logFileHandler = new LogFileHandler(config.compressOnRotation());
+
+ logFileHandler.setFilePattern(config.pattern());
+ logFileHandler.setRotationTimes(config.rotation());
+
+ createSymlink(config, logFileHandler);
+
+ LogFormatter lf = new LogFormatter();
+ lf.messageOnly(true);
+ this.logFileHandler.setFormatter(lf);
+ access.addHandler(this.logFileHandler);
+ }
+
+ private void createSymlink(AccessLogConfig.FileHandler config, LogFileHandler handler) {
+ if (!config.symlink().isEmpty())
+ handler.setSymlinkName(config.symlink());
+ }
+
+ public void shutdown() {
+ logFileHandler.close();
+ access.removeHandler(logFileHandler);
+
+ if (logFileHandler!=null)
+ logFileHandler.shutdown();
+ }
+
+ void rotateNow() {
+ logFileHandler.rotateNow();
+ }
+}
diff --git a/jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLogInterface.java b/jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLogInterface.java
new file mode 100644
index 00000000000..2523174abef
--- /dev/null
+++ b/jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLogInterface.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 AccessLogInterface {
+ void log(AccessLogEntry accessLogEntry);
+}
diff --git a/jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLogSampler.java b/jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLogSampler.java
new file mode 100644
index 00000000000..12d29c2f333
--- /dev/null
+++ b/jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLogSampler.java
@@ -0,0 +1,37 @@
+// 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.concurrent.atomic.AtomicLong;
+
+/**
+ * Samples entries from access log. It first samples every query until it have some data, and then sub-samples
+ * much less frequently to reduce CPU usage and latency impact. It only samples successful requests and requests
+ * that starts with /search.
+ *
+ * @author dybis
+ */
+public class AccessLogSampler implements AccessLogInterface {
+
+ private final AtomicLong accessLineCounter = new AtomicLong(0);
+ private final CircularArrayAccessLogKeeper circularArrayAccessLogKeeper;
+
+ public AccessLogSampler(CircularArrayAccessLogKeeper circularArrayAccessLogKeeper) {
+ this.circularArrayAccessLogKeeper = circularArrayAccessLogKeeper;
+ }
+
+ @Override
+ public void log(AccessLogEntry accessLogEntry) {
+ if (accessLogEntry.getStatusCode() != 200) {
+ return;
+ }
+ String uriString = accessLogEntry.getRawPath();
+ if (! uriString.startsWith("/search")) {
+ return;
+ }
+ final long count = accessLineCounter.incrementAndGet();
+ if (count >= CircularArrayAccessLogKeeper.SIZE && count % CircularArrayAccessLogKeeper.SIZE != 0) {
+ return;
+ }
+ circularArrayAccessLogKeeper.addUri(uriString);
+ }
+}
diff --git a/jdisc_http_service/src/main/java/com/yahoo/container/logging/CircularArrayAccessLogKeeper.java b/jdisc_http_service/src/main/java/com/yahoo/container/logging/CircularArrayAccessLogKeeper.java
new file mode 100644
index 00000000000..dc749c71613
--- /dev/null
+++ b/jdisc_http_service/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/jdisc_http_service/src/main/java/com/yahoo/container/logging/Coverage.java b/jdisc_http_service/src/main/java/com/yahoo/container/logging/Coverage.java
new file mode 100644
index 00000000000..9d122b90641
--- /dev/null
+++ b/jdisc_http_service/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/jdisc_http_service/src/main/java/com/yahoo/container/logging/HitCounts.java b/jdisc_http_service/src/main/java/com/yahoo/container/logging/HitCounts.java
new file mode 100644
index 00000000000..fed12281962
--- /dev/null
+++ b/jdisc_http_service/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/jdisc_http_service/src/main/java/com/yahoo/container/logging/JSONAccessLog.java b/jdisc_http_service/src/main/java/com/yahoo/container/logging/JSONAccessLog.java
new file mode 100644
index 00000000000..a84903467b6
--- /dev/null
+++ b/jdisc_http_service/src/main/java/com/yahoo/container/logging/JSONAccessLog.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;
+
+import java.util.logging.Level;
+
+/**
+ * Log a message in Vespa JSON access log format.
+ *
+ * @author frodelu
+ * @author Tony Vaagenes
+ */
+public final class JSONAccessLog implements AccessLogInterface {
+
+ private final AccessLogHandler logHandler;
+
+ public JSONAccessLog(AccessLogConfig config) {
+ logHandler = new AccessLogHandler(config.fileHandler());
+ }
+
+ @Override
+ public void log(AccessLogEntry logEntry) {
+ logHandler.access.log(Level.INFO, new JSONFormatter(logEntry).format() + '\n');
+ }
+
+ // TODO: This is never called. We should have a DI provider and call this method from its deconstruct.
+ public void shutdown() {
+ logHandler.shutdown();
+ }
+
+ void rotateNow() {
+ logHandler.rotateNow();
+ }
+
+}
diff --git a/jdisc_http_service/src/main/java/com/yahoo/container/logging/JSONFormatter.java b/jdisc_http_service/src/main/java/com/yahoo/container/logging/JSONFormatter.java
new file mode 100644
index 00000000000..ae794e5b60a
--- /dev/null
+++ b/jdisc_http_service/src/main/java/com/yahoo/container/logging/JSONFormatter.java
@@ -0,0 +1,221 @@
+// 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.ByteArrayOutputStream;
+import java.io.IOException;
+import java.math.BigDecimal;
+import java.math.RoundingMode;
+import java.security.Principal;
+import java.util.List;
+import java.util.Map;
+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 {
+ 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 AccessLogEntry accessLogEntry;
+ private final JsonFactory generatorFactory;
+
+ private static Logger logger = Logger.getLogger(JSONFormatter.class.getName());
+
+ public JSONFormatter(final AccessLogEntry entry) {
+ accessLogEntry = entry;
+ generatorFactory = new JsonFactory();
+ generatorFactory.setCodec(new ObjectMapper());
+ }
+
+ /**
+ * The main method for formatting the associated {@link AccessLogEntry} as a Vespa JSON access log string
+ *
+ * @return The Vespa JSON access log string without trailing newline
+ */
+ public String format() {
+ ByteArrayOutputStream logLine = new ByteArrayOutputStream();
+ try {
+ JsonGenerator generator = generatorFactory.createGenerator(logLine, JsonEncoding.UTF8);
+ generator.writeStartObject();
+ generator.writeStringField("ip", accessLogEntry.getIpV4Address());
+ generator.writeNumberField("time", toTimestampInSeconds(accessLogEntry.getTimeStampMillis()));
+ generator.writeNumberField("duration", durationAsSeconds(accessLogEntry.getDurationBetweenRequestResponseMillis()));
+ generator.writeNumberField("responsesize", accessLogEntry.getReturnedContentSize());
+ generator.writeNumberField("code", accessLogEntry.getStatusCode());
+ generator.writeStringField("method", accessLogEntry.getHttpMethod());
+ generator.writeStringField("uri", getNormalizedURI(accessLogEntry.getRawPath(), accessLogEntry.getRawQuery().orElse(null)));
+ generator.writeStringField("version", accessLogEntry.getHttpVersion());
+ generator.writeStringField("agent", accessLogEntry.getUserAgent());
+ generator.writeStringField("host", accessLogEntry.getHostString());
+ generator.writeStringField("scheme", accessLogEntry.getScheme());
+ generator.writeNumberField("localport", accessLogEntry.getLocalPort());
+
+ Principal principal = accessLogEntry.getUserPrincipal();
+ if (principal != null) {
+ generator.writeStringField("user-principal", principal.getName());
+ }
+
+ Principal sslPrincipal = accessLogEntry.getSslPrincipal();
+ if (sslPrincipal != null) {
+ generator.writeStringField("ssl-principal", sslPrincipal.getName());
+ }
+
+ // Only add remote address/port fields if relevant
+ if (remoteAddressDiffers(accessLogEntry.getIpV4Address(), accessLogEntry.getRemoteAddress())) {
+ generator.writeStringField("remoteaddr", accessLogEntry.getRemoteAddress());
+ if (accessLogEntry.getRemotePort() > 0) {
+ generator.writeNumberField("remoteport", accessLogEntry.getRemotePort());
+ }
+ }
+
+ // Only add peer address/port fields if relevant
+ if (accessLogEntry.getPeerAddress() != null) {
+ generator.writeStringField("peeraddr", accessLogEntry.getPeerAddress());
+
+ int peerPort = accessLogEntry.getPeerPort();
+ if (peerPort > 0 && peerPort != accessLogEntry.getRemotePort()) {
+ generator.writeNumberField("peerport", peerPort);
+ }
+ }
+
+ TraceNode trace = accessLogEntry.getTrace();
+ if (trace != null) {
+ long timestamp = trace.timestamp();
+ if (timestamp == 0L) {
+ timestamp = accessLogEntry.getTimeStampMillis();
+ }
+ trace.accept(new TraceRenderer(generator, timestamp));
+ }
+
+ // Only add search sub block of this is a search request
+ if (isSearchRequest(accessLogEntry)) {
+ generator.writeObjectFieldStart("search");
+ generator.writeNumberField("totalhits", getTotalHitCount(accessLogEntry.getHitCounts()));
+ generator.writeNumberField("hits", getRetrievedHitCount(accessLogEntry.getHitCounts()));
+ Coverage c = accessLogEntry.getHitCounts().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
+ Map<String,List<String>> keyValues = accessLogEntry.getKeyValues();
+ if (keyValues != null && !keyValues.isEmpty()) {
+ generator.writeObjectFieldStart("attributes");
+ for (Map.Entry<String,List<String>> entry : keyValues.entrySet()) {
+ if (entry.getValue().size() == 1) {
+ generator.writeStringField(entry.getKey(), entry.getValue().get(0));
+ } else {
+ generator.writeFieldName(entry.getKey());
+ generator.writeStartArray();
+ for (String s : entry.getValue()) {
+ generator.writeString(s);
+ }
+ generator.writeEndArray();
+ }
+ }
+ generator.writeEndObject();
+ }
+
+ generator.writeEndObject();
+ generator.close();
+
+ } catch (IOException e) {
+ logger.log(Level.WARNING, "Unable to generate JSON access log entry: " + e.getMessage());
+ }
+
+ return logLine.toString();
+ }
+
+
+ private boolean remoteAddressDiffers(String ipV4Address, String remoteAddress) {
+ return remoteAddress != null && !Objects.equals(ipV4Address, remoteAddress);
+ }
+
+ private boolean isSearchRequest(AccessLogEntry logEntry) {
+ return logEntry != null && (logEntry.getHitCounts() != null);
+ }
+
+ 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 BigDecimal toTimestampInSeconds(long numMillisSince1Jan1970AtMidnightUTC) {
+ BigDecimal timestampInSeconds =
+ new BigDecimal(numMillisSince1Jan1970AtMidnightUTC).divide(BigDecimal.valueOf(1000));
+
+ if (numMillisSince1Jan1970AtMidnightUTC/1000 > 0x7fffffff) {
+ logger.log(Level.WARNING, "A year 2038 problem occurred.");
+ logger.log(Level.INFO, "numMillisSince1Jan1970AtMidnightUTC: "
+ + numMillisSince1Jan1970AtMidnightUTC);
+ timestampInSeconds =
+ new BigDecimal(numMillisSince1Jan1970AtMidnightUTC)
+ .divide(BigDecimal.valueOf(1000))
+ .remainder(BigDecimal.valueOf(0x7fffffff));
+ }
+ return timestampInSeconds.setScale(3, RoundingMode.HALF_UP);
+ }
+
+ private BigDecimal durationAsSeconds(long timeInMillis) {
+ BigDecimal duration =
+ new BigDecimal(timeInMillis).divide(BigDecimal.valueOf(1000));
+
+ if (timeInMillis > 0xffffffffL) {
+ logger.log(Level.WARNING, "Duration too long: " + timeInMillis);
+ duration = new BigDecimal(0xffffffff);
+ }
+
+ return duration.setScale(3, RoundingMode.HALF_UP);
+ }
+
+ private static String getNormalizedURI(String rawPath, String rawQuery) {
+ return rawQuery != null ? rawPath + "?" + rawQuery : rawPath;
+ }
+
+}
diff --git a/jdisc_http_service/src/main/java/com/yahoo/container/logging/LogFileHandler.java b/jdisc_http_service/src/main/java/com/yahoo/container/logging/LogFileHandler.java
new file mode 100644
index 00000000000..75e9febc192
--- /dev/null
+++ b/jdisc_http_service/src/main/java/com/yahoo/container/logging/LogFileHandler.java
@@ -0,0 +1,397 @@
+// 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.concurrent.ThreadFactoryFactory;
+import com.yahoo.io.NativeIO;
+import com.yahoo.log.LogFileDb;
+import com.yahoo.system.ProcessExecuter;
+import com.yahoo.yolean.Exceptions;
+
+import java.io.File;
+import java.io.FileInputStream;
+import java.io.FileOutputStream;
+import java.io.IOException;
+import java.util.ArrayList;
+import java.util.Arrays;
+import java.util.concurrent.ArrayBlockingQueue;
+import java.util.concurrent.ExecutorService;
+import java.util.concurrent.Executors;
+import java.util.concurrent.TimeUnit;
+import java.util.logging.Level;
+import java.util.logging.LogRecord;
+import java.util.logging.Logger;
+import java.util.logging.StreamHandler;
+import java.util.zip.GZIPOutputStream;
+
+/**
+ * <p>Implements log file naming/rotating logic for container logs.</p>
+ *
+ * <p>Overridden methods: publish</p>
+ *
+ * <p>Added methods: setFilePattern, setRotationTimes, rotateNow (+ few others)</p>
+ *
+ * @author Bob Travis
+ */
+public class LogFileHandler extends StreamHandler {
+
+ private final static Logger logger = Logger.getLogger(LogFileHandler.class.getName());
+ private final boolean compressOnRotation;
+ private long[] rotationTimes = {0}; //default to one log per day, at midnight
+ private String filePattern = "./log.%T"; // default to current directory, ms time stamp
+ private long nextRotationTime = 0;
+ private FileOutputStream currentOutputStream = null;
+ private volatile String fileName;
+ private String symlinkName = null;
+ private ArrayBlockingQueue<LogRecord> logQueue = new ArrayBlockingQueue<>(100000);
+ private LogRecord rotateCmd = new LogRecord(Level.SEVERE, "rotateNow");
+ private ExecutorService executor = Executors.newCachedThreadPool(ThreadFactoryFactory.getDaemonThreadFactory("logfilehandler.compression"));
+ private final NativeIO nativeIO = new NativeIO();
+ private long lastDropPosition = 0;
+
+ static private class LogThread extends Thread {
+ LogFileHandler logFileHandler;
+ long lastFlush = 0;
+ LogThread(LogFileHandler logFile) {
+ super("Logger");
+ setDaemon(true);
+ logFileHandler = logFile;
+ }
+ @Override
+ public void run() {
+ try {
+ storeLogRecords();
+ } catch (InterruptedException e) {
+ } catch (Exception e) {
+ com.yahoo.protect.Process.logAndDie("Failed storing log records", e);
+ }
+
+ logFileHandler.flush();
+ }
+
+ private void storeLogRecords() throws InterruptedException {
+ while (!isInterrupted()) {
+ LogRecord r = logFileHandler.logQueue.poll(100, TimeUnit.MILLISECONDS);
+ if (r != null) {
+ if (r == logFileHandler.rotateCmd) {
+ logFileHandler.internalRotateNow();
+ lastFlush = System.nanoTime();
+ } else {
+ logFileHandler.internalPublish(r);
+ }
+ flushIfOld(3, TimeUnit.SECONDS);
+ } 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)) {
+ logFileHandler.flush();
+ lastFlush = now;
+ }
+ }
+ }
+ private final LogThread logThread;
+
+ LogFileHandler() {
+ this(false);
+ }
+
+ LogFileHandler(boolean compressOnRotation)
+ {
+ super();
+ this.compressOnRotation = compressOnRotation;
+ logThread = new LogThread(this);
+ logThread.start();
+ }
+
+ /**
+ * Sends logrecord to file, first rotating file if needed.
+ *
+ * @param r logrecord to publish
+ */
+ public void publish(LogRecord r) {
+ try {
+ logQueue.put(r);
+ } catch (InterruptedException e) {
+ }
+ }
+
+ @Override
+ public synchronized void flush() {
+ super.flush();
+ try {
+ if (currentOutputStream != null) {
+ long newPos = currentOutputStream.getChannel().position();
+ if (newPos > lastDropPosition + 102400) {
+ nativeIO.dropPartialFileFromCache(currentOutputStream.getFD(), lastDropPosition, newPos, true);
+ lastDropPosition = newPos;
+ }
+ }
+ } catch (IOException e) {
+ logger.warning("Failed dropping from cache : " + Exceptions.toMessageString(e));
+ }
+ }
+
+ private void internalPublish(LogRecord 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 || currentOutputStream == null) {
+ internalRotateNow();
+ }
+ super.publish(r);
+ }
+
+ /**
+ * Assign pattern for generating (rotating) file names.
+ *
+ * @param pattern See LogFormatter for definition
+ */
+ void setFilePattern ( String pattern ) {
+ filePattern = pattern;
+ }
+
+ /**
+ * Assign times for rotating output files.
+ *
+ * @param timesOfDay in millis, from midnight
+ *
+ */
+ void setRotationTimes ( long[] timesOfDay ) {
+ rotationTimes = timesOfDay;
+ }
+
+ /** Assign time for rotating output files
+ *
+ * @param prescription string form of times, in minutes
+ */
+ void setRotationTimes ( String prescription ) {
+ setRotationTimes(calcTimesMinutes(prescription));
+ }
+
+ /**
+ * 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;
+ }
+
+ void waitDrained() {
+ while(! logQueue.isEmpty()) {
+ try {
+ Thread.sleep(1);
+ } catch (InterruptedException e) {
+ }
+ }
+ flush();
+ }
+
+ 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();
+ }
+ }
+ }
+
+ /**
+ * Force file rotation now, independent of schedule.
+ */
+ void rotateNow () {
+ publish(rotateCmd);
+ }
+
+ // 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
+ // use super.setOutputStream to switch to a new file
+
+ String oldFileName = fileName;
+ long now = System.currentTimeMillis();
+ fileName = LogFormatter.insertDate(filePattern, now);
+ flush();
+ super.close();
+
+ try {
+ checkAndCreateDir(fileName);
+ FileOutputStream os = new FileOutputStream(fileName, true); // append mode, for safety
+ super.setOutputStream(os);
+ currentOutputStream = os;
+ lastDropPosition = 0;
+ LogFileDb.nowLoggingTo(fileName);
+ }
+ catch (IOException e) {
+ throw new RuntimeException("Couldn't open log file '" + fileName + "'", e);
+ }
+
+ createSymlinkToCurrentFile();
+
+ nextRotationTime = 0; //figure it out later (lazy evaluation)
+ if ((oldFileName != null)) {
+ File oldFile = new File(oldFileName);
+ if (oldFile.exists()) {
+ if (compressOnRotation) {
+ executor.execute(() -> runCompression(oldFile));
+ } else {
+ nativeIO.dropFileFromCache(oldFile);
+ }
+ }
+ }
+ }
+
+
+ static void runCompression(File oldFile) {
+ File gzippedFile = new File(oldFile.getPath() + ".gz");
+ try (GZIPOutputStream compressor = new GZIPOutputStream(new FileOutputStream(gzippedFile), 0x100000);
+ FileInputStream inputStream = new FileInputStream(oldFile))
+ {
+ byte [] buffer = new byte[0x400000]; // 4M buffer
+
+ long totalBytesRead = 0;
+ NativeIO nativeIO = new NativeIO();
+ for (int read = inputStream.read(buffer); read > 0; read = inputStream.read(buffer)) {
+ compressor.write(buffer, 0, read);
+ nativeIO.dropPartialFileFromCache(inputStream.getFD(), totalBytesRead, read, false);
+ totalBytesRead += read;
+ }
+ compressor.finish();
+ compressor.flush();
+
+ oldFile.delete();
+ nativeIO.dropFileFromCache(gzippedFile);
+ } catch (IOException e) {
+ logger.warning("Got '" + e + "' while compressing '" + oldFile.getPath() + "'.");
+ }
+ }
+
+ /** Name files by date - create a symlink with a constant name to the newest file */
+ private void createSymlinkToCurrentFile() {
+ if (symlinkName == null) return;
+ File f = new File(fileName);
+ File f2 = new File(f.getParent(), symlinkName);
+ String [] cmd = new String[]{"/bin/ln", "-sf", f.getName(), f2.getPath()};
+ try {
+ int retval = new ProcessExecuter().exec(cmd).getFirst();
+ // Detonator pattern: Think of all the fun we can have if ln isn't what we
+ // think it is, if it doesn't return, etc, etc
+ if (retval != 0) {
+ logger.warning("Command '" + Arrays.toString(cmd) + "' + failed with exitcode=" + retval);
+ }
+ } catch (IOException e) {
+ logger.warning("Got '" + e + "' while doing'" + Arrays.toString(cmd) + "'.");
+ }
+ }
+
+ /**
+ * 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;
+ }
+
+ // Support staff :-)
+ private static final long lengthOfDayMillis = 24*60*60*1000; // ? is this close enough ?
+
+ private static long timeOfDayMillis ( long time ) {
+ return time % lengthOfDayMillis;
+ }
+
+ void setSymlinkName(String symlinkName) {
+ this.symlinkName = symlinkName;
+ }
+
+ /**
+ * Flushes all queued messages, interrupts the log thread in this and
+ * waits for it to end before returning
+ */
+ public void shutdown() {
+ logThread.interrupt();
+ try {
+ logThread.join();
+ executor.shutdown();
+ executor.awaitTermination(600, TimeUnit.SECONDS);
+ }
+ catch (InterruptedException e) {
+ }
+ }
+
+ /**
+ * Only for unit testing. Do not use.
+ */
+ public String getFileName() {
+ return fileName;
+ }
+
+}
diff --git a/jdisc_http_service/src/main/java/com/yahoo/container/logging/LogFormatter.java b/jdisc_http_service/src/main/java/com/yahoo/container/logging/LogFormatter.java
new file mode 100644
index 00000000000..cc1dcb579aa
--- /dev/null
+++ b/jdisc_http_service/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/jdisc_http_service/src/main/java/com/yahoo/container/logging/TraceRenderer.java b/jdisc_http_service/src/main/java/com/yahoo/container/logging/TraceRenderer.java
new file mode 100644
index 00000000000..295786aa15d
--- /dev/null
+++ b/jdisc_http_service/src/main/java/com/yahoo/container/logging/TraceRenderer.java
@@ -0,0 +1,185 @@
+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/jdisc_http_service/src/main/java/com/yahoo/container/logging/VespaAccessLog.java b/jdisc_http_service/src/main/java/com/yahoo/container/logging/VespaAccessLog.java
new file mode 100644
index 00000000000..054fc0fcbf7
--- /dev/null
+++ b/jdisc_http_service/src/main/java/com/yahoo/container/logging/VespaAccessLog.java
@@ -0,0 +1,111 @@
+// 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;
+
+import java.text.SimpleDateFormat;
+import java.util.Date;
+import java.util.TimeZone;
+import java.util.logging.Level;
+
+/**
+ * @author Bjorn Borud
+ * @author Oyvind Bakksjo
+ */
+public final class VespaAccessLog implements AccessLogInterface {
+
+ private static final ThreadLocal<SimpleDateFormat> dateFormat = ThreadLocal.withInitial(VespaAccessLog::createDateFormat);
+
+ private final AccessLogHandler logHandler;
+
+ public VespaAccessLog(AccessLogConfig config) {
+ logHandler = new AccessLogHandler(config.fileHandler());
+ }
+
+ 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 void writeLog(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())
+ .append('\n');
+ logHandler.access.log(Level.INFO, 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);
+ }
+
+ /**
+ * TODO: This is never called. We should have a DI provider and call this method from its deconstruct.
+ */
+ public void shutdown() {
+ if (logHandler!=null)
+ logHandler.shutdown();
+ }
+
+ @Override
+ public void log(final AccessLogEntry accessLogEntry) {
+ writeLog(
+ accessLogEntry.getIpV4Address(),
+ accessLogEntry.getUser(),
+ getRequest(
+ accessLogEntry.getHttpMethod(),
+ accessLogEntry.getRawPath(),
+ accessLogEntry.getRawQuery().orElse(null),
+ accessLogEntry.getHttpVersion()),
+ accessLogEntry.getReferer(),
+ accessLogEntry.getUserAgent(),
+ accessLogEntry.getDurationBetweenRequestResponseMillis(),
+ accessLogEntry.getReturnedContentSize(),
+ accessLogEntry.getHitCounts(),
+ accessLogEntry.getStatusCode());
+ }
+}
diff --git a/jdisc_http_service/src/main/java/com/yahoo/container/logging/package-info.java b/jdisc_http_service/src/main/java/com/yahoo/container/logging/package-info.java
new file mode 100644
index 00000000000..fc2abb7b609
--- /dev/null
+++ b/jdisc_http_service/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;
diff --git a/jdisc_http_service/src/main/resources/configdefinitions/container.core.access-log.def b/jdisc_http_service/src/main/resources/configdefinitions/container.core.access-log.def
new file mode 100644
index 00000000000..788fadcdf90
--- /dev/null
+++ b/jdisc_http_service/src/main/resources/configdefinitions/container.core.access-log.def
@@ -0,0 +1,17 @@
+# Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
+namespace=container.core
+
+# File name patterns supporting the expected time variables, e.g. ".%Y%m%d%H%M%S"
+fileHandler.pattern string
+
+# When should rotation happen, in minutes after midnight
+# Does this really need to be configurable?
+# Could just configure "every N minutes" instead
+fileHandler.rotation string default="0 60 ..."
+
+# Use this as the name of the symlink created pointing to the newest file in the "date" naming scheme.
+# This is ignored if the sequence naming scheme is used.
+fileHandler.symlink string default=""
+
+# compress the previous access log after rotation
+fileHandler.compressOnRotation bool default=true
diff --git a/jdisc_http_service/src/test/java/com/yahoo/container/logging/AccessLogSamplerTest.java b/jdisc_http_service/src/test/java/com/yahoo/container/logging/AccessLogSamplerTest.java
new file mode 100644
index 00000000000..32a55b4bb72
--- /dev/null
+++ b/jdisc_http_service/src/test/java/com/yahoo/container/logging/AccessLogSamplerTest.java
@@ -0,0 +1,62 @@
+// 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 org.junit.Test;
+
+import java.util.ArrayList;
+import java.util.List;
+
+import static org.hamcrest.CoreMatchers.hasItem;
+import static org.hamcrest.CoreMatchers.hasItems;
+import static org.hamcrest.CoreMatchers.is;
+import static org.hamcrest.Matchers.contains;
+import static org.junit.Assert.assertThat;
+
+public class AccessLogSamplerTest {
+
+ private final List<String> uris = new ArrayList<>();
+ private CircularArrayAccessLogKeeper circularArrayAccessLogKeeperMock = new CircularArrayAccessLogKeeper() {
+ @Override
+ public void addUri(String uri) {
+ uris.add(uri);
+ }
+ };
+ private AccessLogSampler accessLogSampler = new AccessLogSampler(circularArrayAccessLogKeeperMock);
+
+ @Test
+ public void testAFewLines() {
+ accessLogSampler.log(createLogEntry(200, "/search/foo"));
+ accessLogSampler.log(createLogEntry(500, "/search/bar"));
+ accessLogSampler.log(createLogEntry(500, "bar"));
+ accessLogSampler.log(createLogEntry(200, "/search/what"));
+ assertThat(uris, contains("/search/foo", "/search/what"));
+ }
+
+ @Test
+ public void testSubSampling() {
+ for (int i = 0; i < CircularArrayAccessLogKeeper.SIZE; i++) {
+ accessLogSampler.log(createLogEntry(200, "/search/" + String.valueOf(i)));
+ }
+ assertThat(uris.size(), is(CircularArrayAccessLogKeeper.SIZE));
+ assertThat(uris, hasItems("/search/0", "/search/1", "/search/2",
+ "/search/" + String.valueOf(CircularArrayAccessLogKeeper.SIZE - 1)));
+ uris.clear();
+ for (int i = 0; i < CircularArrayAccessLogKeeper.SIZE; i++) {
+ accessLogSampler.log(createLogEntry(200, "/search/fuzz"));
+ }
+ assertThat(uris, hasItem("/search/fuzz"));
+ assertThat(uris.size(), is(1));
+ for (int i = 0; i < CircularArrayAccessLogKeeper.SIZE; i++) {
+ accessLogSampler.log(createLogEntry(200, "/search/ball"));
+ }
+ assertThat(uris, hasItem("/search/ball"));
+ assertThat(uris.size(), is(2));
+ }
+
+ private AccessLogEntry createLogEntry(int statusCode, String uri) {
+ AccessLogEntry accessLogEntry = new AccessLogEntry();
+ accessLogEntry.setStatusCode(statusCode);
+ accessLogEntry.setRawPath(uri);
+ return accessLogEntry;
+ }
+}
diff --git a/jdisc_http_service/src/test/java/com/yahoo/container/logging/CircularArrayAccessLogKeeperTest.java b/jdisc_http_service/src/test/java/com/yahoo/container/logging/CircularArrayAccessLogKeeperTest.java
new file mode 100644
index 00000000000..5d9509eb045
--- /dev/null
+++ b/jdisc_http_service/src/test/java/com/yahoo/container/logging/CircularArrayAccessLogKeeperTest.java
@@ -0,0 +1,42 @@
+// 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 org.junit.Test;
+
+import static org.hamcrest.CoreMatchers.hasItems;
+import static org.hamcrest.Matchers.contains;
+import static org.hamcrest.core.Is.is;
+import static org.hamcrest.core.IsCollectionContaining.hasItem;
+import static org.hamcrest.core.IsNot.not;
+import static org.junit.Assert.assertThat;
+
+public class CircularArrayAccessLogKeeperTest {
+ private CircularArrayAccessLogKeeper circularArrayAccessLogKeeper = new CircularArrayAccessLogKeeper();
+
+ @Test
+ public void testSizeIsCroppedCorrectly() {
+ for (int i = 0; i < CircularArrayAccessLogKeeper.SIZE - 1; i++) {
+ circularArrayAccessLogKeeper.addUri(String.valueOf(i));
+ }
+ assertThat(circularArrayAccessLogKeeper.getUris().size(), is(CircularArrayAccessLogKeeper.SIZE -1));
+ circularArrayAccessLogKeeper.addUri("foo");
+ assertThat(circularArrayAccessLogKeeper.getUris().size(), is(CircularArrayAccessLogKeeper.SIZE));
+ circularArrayAccessLogKeeper.addUri("bar");
+ assertThat(circularArrayAccessLogKeeper.getUris().size(), is(CircularArrayAccessLogKeeper.SIZE));
+ assertThat(circularArrayAccessLogKeeper.getUris(), hasItems("1", "2", "3", "foo", "bar"));
+ assertThat(circularArrayAccessLogKeeper.getUris(), not(hasItem("0")));
+ }
+
+ @Test
+ public void testEmpty() {
+ assertThat(circularArrayAccessLogKeeper.getUris().size(), is(0));
+ }
+
+ @Test
+ public void testSomeItems() {
+ circularArrayAccessLogKeeper.addUri("a");
+ circularArrayAccessLogKeeper.addUri("b");
+ circularArrayAccessLogKeeper.addUri("b");
+ assertThat(circularArrayAccessLogKeeper.getUris(), contains("a", "b", "b"));
+ }
+}
diff --git a/jdisc_http_service/src/test/java/com/yahoo/container/logging/CompressWhileDrop.java b/jdisc_http_service/src/test/java/com/yahoo/container/logging/CompressWhileDrop.java
new file mode 100644
index 00000000000..2099037203f
--- /dev/null
+++ b/jdisc_http_service/src/test/java/com/yahoo/container/logging/CompressWhileDrop.java
@@ -0,0 +1,11 @@
+// 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;
+
+import java.io.File;
+
+public class CompressWhileDrop {
+ public static void main(String [] args) {
+ System.out.println("Start compressing file " + args[0]);
+ LogFileHandler.runCompression(new File(args[0]));
+ }
+}
diff --git a/jdisc_http_service/src/test/java/com/yahoo/container/logging/JSONLogTestCase.java b/jdisc_http_service/src/test/java/com/yahoo/container/logging/JSONLogTestCase.java
new file mode 100644
index 00000000000..6c7878f99ed
--- /dev/null
+++ b/jdisc_http_service/src/test/java/com/yahoo/container/logging/JSONLogTestCase.java
@@ -0,0 +1,276 @@
+// 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.yolean.trace.TraceNode;
+import org.junit.Test;
+
+import java.io.IOException;
+import java.net.URI;
+
+import static org.junit.Assert.assertEquals;
+
+
+/**
+ * @author frodelu
+ */
+public class JSONLogTestCase {
+
+ private static String ipAddress = "152.200.54.243";
+ private static final String EMPTY_REFERRER = "";
+ private static final String EMPTY_USERAGENT = "";
+
+ private AccessLogEntry newAccessLogEntry(final String query) {
+ return newAccessLogEntry(query, new Coverage(100,100,100,0));
+ }
+ private AccessLogEntry newAccessLogEntry(final String query, Coverage coverage) {
+ final AccessLogEntry entry = new AccessLogEntry();
+ entry.setRawQuery("query="+query);
+ entry.setRawPath("");
+ entry.setIpV4Address(ipAddress);
+ entry.setHttpMethod("GET");
+ entry.setHttpVersion("HTTP/1.1");
+ entry.setUserAgent("Mozilla/4.05 [en] (Win95; I)");
+ entry.setHitCounts(new HitCounts(0, 10, 1234, 0, 10, coverage));
+ entry.setHostString("localhost");
+ entry.setStatusCode(200);
+ entry.setTimeStamp(920880005023L);
+ entry.setDurationBetweenRequestResponse(122);
+ entry.setReturnedContentSize(9875);
+
+ return entry;
+ }
+
+ private static URI newQueryUri(final String query) {
+ return URI.create("http://localhost?query=" + query);
+ }
+
+ @Test
+ public void test_json_log_entry() throws Exception {
+ AccessLogEntry entry = newAccessLogEntry("test");
+
+ String expectedOutput =
+ "{\"ip\":\"152.200.54.243\"," +
+ "\"time\":920880005.023," +
+ "\"duration\":0.122," +
+ "\"responsesize\":9875," +
+ "\"code\":200," +
+ "\"method\":\"GET\"," +
+ "\"uri\":\"?query=test\"," +
+ "\"version\":\"HTTP/1.1\"," +
+ "\"agent\":\"Mozilla/4.05 [en] (Win95; I)\"," +
+ "\"host\":\"localhost\"," +
+ "\"scheme\":null," +
+ "\"localport\":0," +
+ "\"search\":{" +
+ "\"totalhits\":1234," +
+ "\"hits\":0," +
+ "\"coverage\":{\"coverage\":100,\"documents\":100}" +
+ "}" +
+ "}";
+
+ assertEquals(expectedOutput, new JSONFormatter(entry).format());
+ }
+
+ @Test
+ public void test_json_of_trace() throws IOException {
+ TraceNode root = new TraceNode("root", 7);
+ AccessLogEntry entry = newAccessLogEntry("test");
+ entry.setTrace(root);
+
+ String expectedOutput =
+ "{\"ip\":\"152.200.54.243\"," +
+ "\"time\":920880005.023," +
+ "\"duration\":0.122," +
+ "\"responsesize\":9875," +
+ "\"code\":200," +
+ "\"method\":\"GET\"," +
+ "\"uri\":\"?query=test\"," +
+ "\"version\":\"HTTP/1.1\"," +
+ "\"agent\":\"Mozilla/4.05 [en] (Win95; I)\"," +
+ "\"host\":\"localhost\"," +
+ "\"scheme\":null," +
+ "\"localport\":0," +
+ "\"trace\":{\"timestamp\":0,\"message\":\"root\"}," +
+ "\"search\":{" +
+ "\"totalhits\":1234," +
+ "\"hits\":0," +
+ "\"coverage\":{\"coverage\":100,\"documents\":100}" +
+ "}" +
+ "}";
+
+ assertEquals(expectedOutput, new JSONFormatter(entry).format());
+ }
+
+ @Test
+ public void test_with_keyvalues() {
+ AccessLogEntry entry = newAccessLogEntry("test");
+ entry.addKeyValue("singlevalue", "value1");
+ entry.addKeyValue("multivalue", "value2");
+ entry.addKeyValue("multivalue", "value3");
+
+ String expectedOutput =
+ "{\"ip\":\"152.200.54.243\"," +
+ "\"time\":920880005.023," +
+ "\"duration\":0.122," +
+ "\"responsesize\":9875," +
+ "\"code\":200," +
+ "\"method\":\"GET\"," +
+ "\"uri\":\"?query=test\"," +
+ "\"version\":\"HTTP/1.1\"," +
+ "\"agent\":\"Mozilla/4.05 [en] (Win95; I)\"," +
+ "\"host\":\"localhost\"," +
+ "\"scheme\":null," +
+ "\"localport\":0," +
+ "\"search\":{" +
+ "\"totalhits\":1234," +
+ "\"hits\":0," +
+ "\"coverage\":{\"coverage\":100,\"documents\":100}" +
+ "}," +
+ "\"attributes\":{" +
+ "\"singlevalue\":\"value1\"," +
+ "\"multivalue\":[\"value2\",\"value3\"]}" +
+ "}";
+
+ assertEquals(expectedOutput, new JSONFormatter(entry).format());
+
+ }
+
+ @Test
+ public void test_with_remoteaddrport() throws Exception {
+ AccessLogEntry entry = newAccessLogEntry("test");
+
+ // First test with only remote address and not port set
+ entry.setRemoteAddress("FE80:0000:0000:0000:0202:B3FF:FE1E:8329");
+
+ String expectedOutput =
+ "{\"ip\":\"152.200.54.243\"," +
+ "\"time\":920880005.023," +
+ "\"duration\":0.122," +
+ "\"responsesize\":9875," +
+ "\"code\":200," +
+ "\"method\":\"GET\"," +
+ "\"uri\":\"?query=test\"," +
+ "\"version\":\"HTTP/1.1\"," +
+ "\"agent\":\"Mozilla/4.05 [en] (Win95; I)\"," +
+ "\"host\":\"localhost\"," +
+ "\"scheme\":null," +
+ "\"localport\":0," +
+ "\"remoteaddr\":\"FE80:0000:0000:0000:0202:B3FF:FE1E:8329\"," +
+ "\"search\":{" +
+ "\"totalhits\":1234," +
+ "\"hits\":0," +
+ "\"coverage\":{\"coverage\":100,\"documents\":100}" +
+ "}" +
+ "}";
+
+ assertEquals(expectedOutput, new JSONFormatter(entry).format());
+
+ // Add remote port and verify
+ entry.setRemotePort(1234);
+
+ expectedOutput =
+ "{\"ip\":\"152.200.54.243\"," +
+ "\"time\":920880005.023," +
+ "\"duration\":0.122," +
+ "\"responsesize\":9875," +
+ "\"code\":200," +
+ "\"method\":\"GET\"," +
+ "\"uri\":\"?query=test\"," +
+ "\"version\":\"HTTP/1.1\"," +
+ "\"agent\":\"Mozilla/4.05 [en] (Win95; I)\"," +
+ "\"host\":\"localhost\"," +
+ "\"scheme\":null," +
+ "\"localport\":0," +
+ "\"remoteaddr\":\"FE80:0000:0000:0000:0202:B3FF:FE1E:8329\"," +
+ "\"remoteport\":1234," +
+ "\"search\":{" +
+ "\"totalhits\":1234," +
+ "\"hits\":0," +
+ "\"coverage\":{\"coverage\":100,\"documents\":100}" +
+ "}" +
+ "}";
+
+ assertEquals(expectedOutput, new JSONFormatter(entry).format());
+ }
+
+ @Test
+ public void test_remote_address_same_as_ip_address() throws Exception {
+ AccessLogEntry entry = newAccessLogEntry("test");
+ AccessLogEntry entrywithremote = newAccessLogEntry("test");
+ entrywithremote.setRemoteAddress(entry.getIpV4Address());
+
+ assertEquals(new JSONFormatter(entry).format(), new JSONFormatter(entrywithremote).format());
+ }
+
+ @Test
+ public void test_useragent_with_quotes() {
+ final AccessLogEntry entry = new AccessLogEntry();
+ entry.setRawQuery("query=test");
+ entry.setRawPath("");
+ entry.setIpV4Address(ipAddress);
+ entry.setHttpMethod("GET");
+ entry.setHttpVersion("HTTP/1.1");
+ entry.setUserAgent("Mozilla/4.05 [en] (Win95; I; \"Best Browser Ever\")");
+ entry.setHitCounts(new HitCounts(0, 10, 1234, 0, 10, new Coverage(100,200,200,0)));
+ entry.setHostString("localhost");
+ entry.setStatusCode(200);
+ entry.setTimeStamp(920880005023L);
+ entry.setDurationBetweenRequestResponse(122);
+ entry.setReturnedContentSize(9875);
+
+ String expectedOutput =
+ "{\"ip\":\"152.200.54.243\"," +
+ "\"time\":920880005.023," +
+ "\"duration\":0.122," +
+ "\"responsesize\":9875," +
+ "\"code\":200," +
+ "\"method\":\"GET\"," +
+ "\"uri\":\"?query=test\"," +
+ "\"version\":\"HTTP/1.1\"," +
+ "\"agent\":\"Mozilla/4.05 [en] (Win95; I; \\\"Best Browser Ever\\\")\"," +
+ "\"host\":\"localhost\"," +
+ "\"scheme\":null," +
+ "\"localport\":0," +
+ "\"search\":{" +
+ "\"totalhits\":1234," +
+ "\"hits\":0," +
+ "\"coverage\":{\"coverage\":50,\"documents\":100,\"degraded\":{\"non-ideal-state\":true}}" +
+ "}" +
+ "}";
+
+ assertEquals(expectedOutput, new JSONFormatter(entry).format());
+ }
+
+ private void verifyCoverage(String coverage, AccessLogEntry entry) {
+ assertEquals("{\"ip\":\"152.200.54.243\"," +
+ "\"time\":920880005.023," +
+ "\"duration\":0.122," +
+ "\"responsesize\":9875," +
+ "\"code\":200," +
+ "\"method\":\"GET\"," +
+ "\"uri\":\"?query=test\"," +
+ "\"version\":\"HTTP/1.1\"," +
+ "\"agent\":\"Mozilla/4.05 [en] (Win95; I)\"," +
+ "\"host\":\"localhost\"," +
+ "\"scheme\":null," +
+ "\"localport\":0," +
+ "\"search\":{" +
+ "\"totalhits\":1234," +
+ "\"hits\":0," +
+ coverage +
+ "}" +
+ "}", new JSONFormatter(entry).format());
+ }
+
+ @Test
+ public void test_with_coverage_degradation() {
+ verifyCoverage("\"coverage\":{\"coverage\":50,\"documents\":100,\"degraded\":{\"non-ideal-state\":true}}",
+ newAccessLogEntry("test", new Coverage(100,200,200,0)));
+ verifyCoverage("\"coverage\":{\"coverage\":50,\"documents\":100,\"degraded\":{\"match-phase\":true}}",
+ newAccessLogEntry("test", new Coverage(100,200,200,1)));
+ verifyCoverage("\"coverage\":{\"coverage\":50,\"documents\":100,\"degraded\":{\"timeout\":true}}",
+ newAccessLogEntry("test", new Coverage(100,200,200,2)));
+ verifyCoverage("\"coverage\":{\"coverage\":50,\"documents\":100,\"degraded\":{\"adaptive-timeout\":true}}",
+ newAccessLogEntry("test", new Coverage(100,200,200,4)));
+ }
+}
diff --git a/jdisc_http_service/src/test/java/com/yahoo/container/logging/LogFileHandlerTestCase.java b/jdisc_http_service/src/test/java/com/yahoo/container/logging/LogFileHandlerTestCase.java
new file mode 100644
index 00000000000..bc7257b1ca9
--- /dev/null
+++ b/jdisc_http_service/src/test/java/com/yahoo/container/logging/LogFileHandlerTestCase.java
@@ -0,0 +1,187 @@
+// 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.io.IOUtils;
+import org.junit.Rule;
+import org.junit.Test;
+import org.junit.rules.TemporaryFolder;
+
+import java.io.File;
+import java.io.FileInputStream;
+import java.io.IOException;
+import java.io.InputStreamReader;
+import java.nio.file.Files;
+import java.nio.file.Paths;
+import java.text.DateFormat;
+import java.text.SimpleDateFormat;
+import java.util.Date;
+import java.util.logging.Formatter;
+import java.util.logging.Level;
+import java.util.logging.LogRecord;
+import java.util.logging.SimpleFormatter;
+import java.util.zip.GZIPInputStream;
+
+import static org.assertj.core.api.Assertions.assertThat;
+
+/**
+ * @author Bob Travis
+ * @author bjorncs
+ */
+public class LogFileHandlerTestCase {
+
+ @Rule
+ public TemporaryFolder temporaryFolder = new TemporaryFolder();
+
+ @Test
+ public void testIt() throws IOException {
+ File root = temporaryFolder.newFolder("logfilehandlertest");
+
+ LogFileHandler h = new LogFileHandler();
+ h.setFilePattern(root.getAbsolutePath() + "/logfilehandlertest.%Y%m%d%H%M%S");
+ h.setFormatter(new Formatter() {
+ public String format(LogRecord r) {
+ DateFormat df = new SimpleDateFormat("yyyy.MM.dd:HH:mm:ss.SSS");
+ String timeStamp = df.format(new Date(r.getMillis()));
+ return ("["+timeStamp+"]" + " " + formatMessage(r) + "\n");
+ }
+ } );
+ long now = System.currentTimeMillis();
+ long millisPerDay = 60*60*24*1000;
+ long tomorrowDays = (now / millisPerDay) +1;
+ long tomorrowMillis = tomorrowDays * millisPerDay;
+ assertThat(tomorrowMillis).isEqualTo(h.getNextRotationTime(now));
+ long[] rTimes = {1000, 2000, 10000};
+ h.setRotationTimes(rTimes);
+ assertThat(tomorrowMillis+1000).isEqualTo(h.getNextRotationTime(tomorrowMillis));
+ assertThat(tomorrowMillis+10000).isEqualTo(h.getNextRotationTime(tomorrowMillis+3000));
+ LogRecord lr = new LogRecord(Level.INFO, "test");
+ h.publish(lr);
+ h.publish(new LogRecord(Level.INFO, "another test"));
+ h.rotateNow();
+ h.publish(lr);
+ h.flush();
+ h.shutdown();
+ }
+
+ @Test
+ public void testSimpleLogging() throws IOException {
+ File logFile = temporaryFolder.newFile("testLogFileG1.txt");
+
+ //create logfilehandler
+ LogFileHandler h = new LogFileHandler();
+ h.setFilePattern(logFile.getAbsolutePath());
+ h.setFormatter(new SimpleFormatter());
+ h.setRotationTimes("0 5 ...");
+
+ //write log
+ LogRecord lr = new LogRecord(Level.INFO, "testDeleteFileFirst1");
+ h.publish(lr);
+ h.flush();
+ h.shutdown();
+ }
+
+ @Test
+ public void testDeleteFileDuringLogging() throws IOException {
+ File logFile = temporaryFolder.newFile("testLogFileG2.txt");
+
+ //create logfilehandler
+ LogFileHandler h = new LogFileHandler();
+ h.setFilePattern(logFile.getAbsolutePath());
+ h.setFormatter(new SimpleFormatter());
+ h.setRotationTimes("0 5 ...");
+
+ //write log
+ LogRecord lr = new LogRecord(Level.INFO, "testDeleteFileDuringLogging1");
+ h.publish(lr);
+ h.flush();
+
+ //delete log file
+ logFile.delete();
+
+ //write log again
+ lr = new LogRecord(Level.INFO, "testDeleteFileDuringLogging2");
+ h.publish(lr);
+ h.flush();
+ h.shutdown();
+ }
+
+ @Test(timeout = /*5 minutes*/300_000)
+ public void testSymlink() throws IOException, InterruptedException {
+ File root = temporaryFolder.newFolder("testlogforsymlinkchecking");
+ LogFileHandler handler = new LogFileHandler();
+ handler.setFilePattern(root.getAbsolutePath() + "/logfilehandlertest.%Y%m%d%H%M%S%s");
+ handler.setFormatter(new Formatter() {
+ public String format(LogRecord r) {
+ DateFormat df = new SimpleDateFormat("yyyy.MM.dd:HH:mm:ss.SSS");
+ String timeStamp = df.format(new Date(r.getMillis()));
+ return ("["+timeStamp+"]" + " " + formatMessage(r) + "\n");
+ }
+ } );
+ handler.setSymlinkName("symlink");
+
+ handler.publish(new LogRecord(Level.INFO, "test"));
+ String firstFile;
+ do {
+ Thread.sleep(1);
+ firstFile = handler.getFileName();
+ } while (firstFile == null);
+ handler.rotateNow();
+ String secondFileName;
+ do {
+ Thread.sleep(1);
+ secondFileName = handler.getFileName();
+ } while (firstFile.equals(secondFileName));
+
+ handler.publish(new LogRecord(Level.INFO, "string which is way longer than the word test"));
+ handler.waitDrained();
+ assertThat(Files.size(Paths.get(firstFile))).isEqualTo(31);
+ final long expectedSecondFileLength = 72;
+ long secondFileLength;
+ do {
+ Thread.sleep(1);
+ secondFileLength = Files.size(Paths.get(secondFileName));
+ } while (secondFileLength != expectedSecondFileLength);
+
+ long symlinkFileLength = Files.size(root.toPath().resolve("symlink"));
+ assertThat(symlinkFileLength).isEqualTo(expectedSecondFileLength);
+ handler.shutdown();
+ }
+
+ @Test
+ public void testcompression() throws InterruptedException, IOException {
+ File root = temporaryFolder.newFolder("testcompression");
+
+ LogFileHandler h = new LogFileHandler(true);
+ h.setFilePattern(root.getAbsolutePath() + "/logfilehandlertest.%Y%m%d%H%M%S%s");
+ h.setFormatter(new Formatter() {
+ public String format(LogRecord r) {
+ DateFormat df = new SimpleDateFormat("yyyy.MM.dd:HH:mm:ss.SSS");
+ String timeStamp = df.format(new Date(r.getMillis()));
+ return ("["+timeStamp+"]" + " " + formatMessage(r) + "\n");
+ }
+ } );
+ int logEntries = 10000;
+ for (int i = 0; i < logEntries; i++) {
+ LogRecord lr = new LogRecord(Level.INFO, "test");
+ h.publish(lr);
+ }
+ h.waitDrained();
+ String f1 = h.getFileName();
+ assertThat(f1).startsWith(root.getAbsolutePath() + "/logfilehandlertest.");
+ File uncompressed = new File(f1);
+ File compressed = new File(f1 + ".gz");
+ assertThat(uncompressed).exists();
+ assertThat(compressed).doesNotExist();
+ String content = IOUtils.readFile(uncompressed);
+ assertThat(content).hasLineCount(logEntries);
+ h.rotateNow();
+ while (uncompressed.exists()) {
+ Thread.sleep(1);
+ }
+ assertThat(compressed).exists();
+ String unzipped = IOUtils.readAll(new InputStreamReader(new GZIPInputStream(new FileInputStream(compressed))));
+ assertThat(content).isEqualTo(unzipped);
+ h.shutdown();
+ }
+
+}
diff --git a/jdisc_http_service/src/test/java/com/yahoo/container/logging/test/LogFormatterTestCase.java b/jdisc_http_service/src/test/java/com/yahoo/container/logging/test/LogFormatterTestCase.java
new file mode 100644
index 00000000000..ecacf95d100
--- /dev/null
+++ b/jdisc_http_service/src/test/java/com/yahoo/container/logging/test/LogFormatterTestCase.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.test;
+
+import com.yahoo.container.logging.LogFormatter;
+import org.junit.Test;
+
+import java.util.Date;
+
+import static org.junit.Assert.assertEquals;
+
+/**
+ * @author Bob Travis
+ */
+public class LogFormatterTestCase {
+
+ @Test
+ public void testIt() {
+ java.util.TimeZone.setDefault(java.util.TimeZone.getTimeZone("UTC"));
+ @SuppressWarnings("deprecation")
+ long time = new Date(103,7,25,13,30,35).getTime();
+ String result = LogFormatter.insertDate("test%Y%m%d%H%M%S%x",time);
+ assertEquals("test20030825133035Aug",result);
+ result = LogFormatter.insertDate("test%s%T",time);
+ assertEquals("test000"+time, result);
+ }
+
+}