From bd9d35c912d4c08c8e73b876348278fa968eceaa Mon Sep 17 00:00:00 2001 From: Bjørn Christian Seime Date: Mon, 11 Jan 2021 16:46:32 +0100 Subject: Revert "Revert "Merge container-accesslogging into jdisc_http_service"" --- CMakeLists.txt | 1 - cloud-tenant-base-dependencies-enforcer/pom.xml | 1 - container-accesslogging/CMakeLists.txt | 2 - container-accesslogging/OWNERS | 1 - container-accesslogging/README.md | 4 - container-accesslogging/pom.xml | 97 ---- .../com/yahoo/container/logging/AccessLog.java | 32 -- .../yahoo/container/logging/AccessLogEntry.java | 522 --------------------- .../yahoo/container/logging/AccessLogHandler.java | 48 -- .../container/logging/AccessLogInterface.java | 9 - .../yahoo/container/logging/AccessLogSampler.java | 37 -- .../logging/CircularArrayAccessLogKeeper.java | 48 -- .../java/com/yahoo/container/logging/Coverage.java | 64 --- .../com/yahoo/container/logging/HitCounts.java | 78 --- .../com/yahoo/container/logging/JSONAccessLog.java | 36 -- .../com/yahoo/container/logging/JSONFormatter.java | 221 --------- .../yahoo/container/logging/LogFileHandler.java | 397 ---------------- .../com/yahoo/container/logging/LogFormatter.java | 191 -------- .../com/yahoo/container/logging/TraceRenderer.java | 185 -------- .../yahoo/container/logging/VespaAccessLog.java | 111 ----- .../com/yahoo/container/logging/package-info.java | 5 - .../container.core.access-log.def | 17 - .../container/logging/AccessLogSamplerTest.java | 63 --- .../logging/CircularArrayAccessLogKeeperTest.java | 42 -- .../yahoo/container/logging/CompressWhileDrop.java | 11 - .../yahoo/container/logging/JSONLogTestCase.java | 276 ----------- .../container/logging/LogFileHandlerTestCase.java | 187 -------- .../logging/test/LogFormatterTestCase.java | 27 -- container-core/pom.xml | 5 - container-search/pom.xml | 6 - jdisc_http_service/pom.xml | 12 +- .../com/yahoo/container/logging/AccessLog.java | 32 ++ .../yahoo/container/logging/AccessLogEntry.java | 522 +++++++++++++++++++++ .../yahoo/container/logging/AccessLogHandler.java | 48 ++ .../container/logging/AccessLogInterface.java | 9 + .../yahoo/container/logging/AccessLogSampler.java | 37 ++ .../logging/CircularArrayAccessLogKeeper.java | 48 ++ .../java/com/yahoo/container/logging/Coverage.java | 64 +++ .../com/yahoo/container/logging/HitCounts.java | 78 +++ .../com/yahoo/container/logging/JSONAccessLog.java | 36 ++ .../com/yahoo/container/logging/JSONFormatter.java | 221 +++++++++ .../yahoo/container/logging/LogFileHandler.java | 397 ++++++++++++++++ .../com/yahoo/container/logging/LogFormatter.java | 191 ++++++++ .../com/yahoo/container/logging/TraceRenderer.java | 185 ++++++++ .../yahoo/container/logging/VespaAccessLog.java | 111 +++++ .../com/yahoo/container/logging/package-info.java | 5 + .../container.core.access-log.def | 17 + .../container/logging/AccessLogSamplerTest.java | 62 +++ .../logging/CircularArrayAccessLogKeeperTest.java | 42 ++ .../yahoo/container/logging/CompressWhileDrop.java | 11 + .../yahoo/container/logging/JSONLogTestCase.java | 276 +++++++++++ .../container/logging/LogFileHandlerTestCase.java | 187 ++++++++ .../logging/test/LogFormatterTestCase.java | 27 ++ pom.xml | 1 - 54 files changed, 2615 insertions(+), 2728 deletions(-) delete mode 100644 container-accesslogging/CMakeLists.txt delete mode 100644 container-accesslogging/OWNERS delete mode 100644 container-accesslogging/README.md delete mode 100644 container-accesslogging/pom.xml delete mode 100644 container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLog.java delete mode 100644 container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLogEntry.java delete mode 100644 container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLogHandler.java delete mode 100644 container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLogInterface.java delete mode 100644 container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLogSampler.java delete mode 100644 container-accesslogging/src/main/java/com/yahoo/container/logging/CircularArrayAccessLogKeeper.java delete mode 100644 container-accesslogging/src/main/java/com/yahoo/container/logging/Coverage.java delete mode 100644 container-accesslogging/src/main/java/com/yahoo/container/logging/HitCounts.java delete mode 100644 container-accesslogging/src/main/java/com/yahoo/container/logging/JSONAccessLog.java delete mode 100644 container-accesslogging/src/main/java/com/yahoo/container/logging/JSONFormatter.java delete mode 100644 container-accesslogging/src/main/java/com/yahoo/container/logging/LogFileHandler.java delete mode 100644 container-accesslogging/src/main/java/com/yahoo/container/logging/LogFormatter.java delete mode 100644 container-accesslogging/src/main/java/com/yahoo/container/logging/TraceRenderer.java delete mode 100644 container-accesslogging/src/main/java/com/yahoo/container/logging/VespaAccessLog.java delete mode 100644 container-accesslogging/src/main/java/com/yahoo/container/logging/package-info.java delete mode 100644 container-accesslogging/src/main/resources/configdefinitions/container.core.access-log.def delete mode 100644 container-accesslogging/src/test/java/com/yahoo/container/logging/AccessLogSamplerTest.java delete mode 100644 container-accesslogging/src/test/java/com/yahoo/container/logging/CircularArrayAccessLogKeeperTest.java delete mode 100644 container-accesslogging/src/test/java/com/yahoo/container/logging/CompressWhileDrop.java delete mode 100644 container-accesslogging/src/test/java/com/yahoo/container/logging/JSONLogTestCase.java delete mode 100644 container-accesslogging/src/test/java/com/yahoo/container/logging/LogFileHandlerTestCase.java delete mode 100644 container-accesslogging/src/test/java/com/yahoo/container/logging/test/LogFormatterTestCase.java create mode 100644 jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLog.java create mode 100644 jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLogEntry.java create mode 100644 jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLogHandler.java create mode 100644 jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLogInterface.java create mode 100644 jdisc_http_service/src/main/java/com/yahoo/container/logging/AccessLogSampler.java create mode 100644 jdisc_http_service/src/main/java/com/yahoo/container/logging/CircularArrayAccessLogKeeper.java create mode 100644 jdisc_http_service/src/main/java/com/yahoo/container/logging/Coverage.java create mode 100644 jdisc_http_service/src/main/java/com/yahoo/container/logging/HitCounts.java create mode 100644 jdisc_http_service/src/main/java/com/yahoo/container/logging/JSONAccessLog.java create mode 100644 jdisc_http_service/src/main/java/com/yahoo/container/logging/JSONFormatter.java create mode 100644 jdisc_http_service/src/main/java/com/yahoo/container/logging/LogFileHandler.java create mode 100644 jdisc_http_service/src/main/java/com/yahoo/container/logging/LogFormatter.java create mode 100644 jdisc_http_service/src/main/java/com/yahoo/container/logging/TraceRenderer.java create mode 100644 jdisc_http_service/src/main/java/com/yahoo/container/logging/VespaAccessLog.java create mode 100644 jdisc_http_service/src/main/java/com/yahoo/container/logging/package-info.java create mode 100644 jdisc_http_service/src/main/resources/configdefinitions/container.core.access-log.def create mode 100644 jdisc_http_service/src/test/java/com/yahoo/container/logging/AccessLogSamplerTest.java create mode 100644 jdisc_http_service/src/test/java/com/yahoo/container/logging/CircularArrayAccessLogKeeperTest.java create mode 100644 jdisc_http_service/src/test/java/com/yahoo/container/logging/CompressWhileDrop.java create mode 100644 jdisc_http_service/src/test/java/com/yahoo/container/logging/JSONLogTestCase.java create mode 100644 jdisc_http_service/src/test/java/com/yahoo/container/logging/LogFileHandlerTestCase.java create mode 100644 jdisc_http_service/src/test/java/com/yahoo/container/logging/test/LogFormatterTestCase.java diff --git a/CMakeLists.txt b/CMakeLists.txt index aadd31ec2b9..c8cf6a4467a 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -60,7 +60,6 @@ add_subdirectory(configgen) add_subdirectory(configserver) add_subdirectory(configserver-flags) add_subdirectory(configutil) -add_subdirectory(container-accesslogging) add_subdirectory(container-core) add_subdirectory(container-di) add_subdirectory(container-disc) diff --git a/cloud-tenant-base-dependencies-enforcer/pom.xml b/cloud-tenant-base-dependencies-enforcer/pom.xml index 414039ac492..ecf1ce48eb5 100644 --- a/cloud-tenant-base-dependencies-enforcer/pom.xml +++ b/cloud-tenant-base-dependencies-enforcer/pom.xml @@ -145,7 +145,6 @@ com.yahoo.vespa:config:*:jar:provided com.yahoo.vespa:configdefinitions:*:jar:provided com.yahoo.vespa:configgen:*:jar:provided - com.yahoo.vespa:container-accesslogging:*:jar:provided com.yahoo.vespa:container-core:*:jar:provided com.yahoo.vespa:container-dev:*:jar:provided com.yahoo.vespa:container-di:*:jar:provided diff --git a/container-accesslogging/CMakeLists.txt b/container-accesslogging/CMakeLists.txt deleted file mode 100644 index 7bb25e6a420..00000000000 --- a/container-accesslogging/CMakeLists.txt +++ /dev/null @@ -1,2 +0,0 @@ -# Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. -install_config_definitions() diff --git a/container-accesslogging/OWNERS b/container-accesslogging/OWNERS deleted file mode 100644 index 569bf1cc3a1..00000000000 --- a/container-accesslogging/OWNERS +++ /dev/null @@ -1 +0,0 @@ -bjorncs diff --git a/container-accesslogging/README.md b/container-accesslogging/README.md deleted file mode 100644 index 1d5b7d140e9..00000000000 --- a/container-accesslogging/README.md +++ /dev/null @@ -1,4 +0,0 @@ - -# Access logging for JDisc - -Contains various access log implementations for JDisc. diff --git a/container-accesslogging/pom.xml b/container-accesslogging/pom.xml deleted file mode 100644 index ba544e04fc8..00000000000 --- a/container-accesslogging/pom.xml +++ /dev/null @@ -1,97 +0,0 @@ - - - - 4.0.0 - - com.yahoo.vespa - parent - 7-SNAPSHOT - ../parent/pom.xml - - container-accesslogging - 7-SNAPSHOT - container-plugin - - - junit - junit - test - - - com.google.inject - guice - provided - no_aop - - - com.yahoo.vespa - component - ${project.version} - provided - - - com.yahoo.vespa - config-bundle - ${project.version} - provided - - - com.yahoo.vespa - config-lib - ${project.version} - provided - - - com.yahoo.vespa - vespajlib - ${project.version} - provided - - - com.yahoo.vespa - vespalog - ${project.version} - provided - - - org.hamcrest - hamcrest-all - test - - - com.fasterxml.jackson.core - jackson-core - provided - - - com.fasterxml.jackson.core - jackson-databind - provided - - - org.assertj - assertj-core - test - - - - - - com.yahoo.vespa - bundle-plugin - true - - - org.apache.maven.plugins - maven-compiler-plugin - - - ${buildOutputDirectory} - - - ${project.build.directory}/classes/ - - diff --git a/container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLog.java b/container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLog.java deleted file mode 100644 index 5c1a549070c..00000000000 --- a/container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLog.java +++ /dev/null @@ -1,32 +0,0 @@ -// 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 implementers; - - @Inject - public AccessLog(ComponentRegistry 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/container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLogEntry.java b/container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLogEntry.java deleted file mode 100644 index d8085cc808b..00000000000 --- a/container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLogEntry.java +++ /dev/null @@ -1,522 +0,0 @@ -// 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; - -/** - *

Information to be logged in the access log.

- * - *

This class contains the union of all information that can be - * logged with all the supported access log formats.

- * - *

The add methods can be called multiple times, - * but the parameters should be different for each - * invocation of the same method.

- * - * 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 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> getKeyValues() { - synchronized (monitor) { - if (keyValues == null) { - return null; - } - - final Map> newMapWithImmutableValues = mapValues( - keyValues.entrySet(), - valueList -> Collections.unmodifiableList(new ArrayList<>(valueList))); - return Collections.unmodifiableMap(newMapWithImmutableValues); - } - } - - private static Map mapValues( - final Set> entrySet, - final Function 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 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/container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLogHandler.java b/container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLogHandler.java deleted file mode 100644 index 488a6137cc2..00000000000 --- a/container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLogHandler.java +++ /dev/null @@ -1,48 +0,0 @@ -// 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/container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLogInterface.java b/container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLogInterface.java deleted file mode 100644 index 2523174abef..00000000000 --- a/container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLogInterface.java +++ /dev/null @@ -1,9 +0,0 @@ -// 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/container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLogSampler.java b/container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLogSampler.java deleted file mode 100644 index 12d29c2f333..00000000000 --- a/container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLogSampler.java +++ /dev/null @@ -1,37 +0,0 @@ -// 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/container-accesslogging/src/main/java/com/yahoo/container/logging/CircularArrayAccessLogKeeper.java b/container-accesslogging/src/main/java/com/yahoo/container/logging/CircularArrayAccessLogKeeper.java deleted file mode 100644 index dc749c71613..00000000000 --- a/container-accesslogging/src/main/java/com/yahoo/container/logging/CircularArrayAccessLogKeeper.java +++ /dev/null @@ -1,48 +0,0 @@ -// 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 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 getUris() { - final List 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-accesslogging/src/main/java/com/yahoo/container/logging/Coverage.java b/container-accesslogging/src/main/java/com/yahoo/container/logging/Coverage.java deleted file mode 100644 index 9d122b90641..00000000000 --- a/container-accesslogging/src/main/java/com/yahoo/container/logging/Coverage.java +++ /dev/null @@ -1,64 +0,0 @@ -// 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-accesslogging/src/main/java/com/yahoo/container/logging/HitCounts.java b/container-accesslogging/src/main/java/com/yahoo/container/logging/HitCounts.java deleted file mode 100644 index fed12281962..00000000000 --- a/container-accesslogging/src/main/java/com/yahoo/container/logging/HitCounts.java +++ /dev/null @@ -1,78 +0,0 @@ -// 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 Steinar Knutsen - */ -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-accesslogging/src/main/java/com/yahoo/container/logging/JSONAccessLog.java b/container-accesslogging/src/main/java/com/yahoo/container/logging/JSONAccessLog.java deleted file mode 100644 index a84903467b6..00000000000 --- a/container-accesslogging/src/main/java/com/yahoo/container/logging/JSONAccessLog.java +++ /dev/null @@ -1,36 +0,0 @@ -// 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/container-accesslogging/src/main/java/com/yahoo/container/logging/JSONFormatter.java b/container-accesslogging/src/main/java/com/yahoo/container/logging/JSONFormatter.java deleted file mode 100644 index ae794e5b60a..00000000000 --- a/container-accesslogging/src/main/java/com/yahoo/container/logging/JSONFormatter.java +++ /dev/null @@ -1,221 +0,0 @@ -// 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> keyValues = accessLogEntry.getKeyValues(); - if (keyValues != null && !keyValues.isEmpty()) { - generator.writeObjectFieldStart("attributes"); - for (Map.Entry> 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/container-accesslogging/src/main/java/com/yahoo/container/logging/LogFileHandler.java b/container-accesslogging/src/main/java/com/yahoo/container/logging/LogFileHandler.java deleted file mode 100644 index 75e9febc192..00000000000 --- a/container-accesslogging/src/main/java/com/yahoo/container/logging/LogFileHandler.java +++ /dev/null @@ -1,397 +0,0 @@ -// 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; - -/** - *

Implements log file naming/rotating logic for container logs.

- * - *

Overridden methods: publish

- * - *

Added methods: setFilePattern, setRotationTimes, rotateNow (+ few others)

- * - * @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 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 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 0) { - int newsize = size + (int)moreneeded; - long[] temp = new long[newsize]; - for (i=0; i - *
  • %Y YYYY 2003 - *
  • %m MM 08 - *
  • %x MMM Aug - *
  • %d dd 25 - *
  • %H HH 14 - *
  • %M mm 30 - *
  • %S ss 35 - *
  • %s SSS 123 - *
  • %Z Z -0400 - * - *Others: - *
      - *
    • %T Long.toString(time) - *
    • %% % - *
    - */ - 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-accesslogging/src/main/java/com/yahoo/container/logging/TraceRenderer.java b/container-accesslogging/src/main/java/com/yahoo/container/logging/TraceRenderer.java deleted file mode 100644 index 295786aa15d..00000000000 --- a/container-accesslogging/src/main/java/com/yahoo/container/logging/TraceRenderer.java +++ /dev/null @@ -1,185 +0,0 @@ -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-accesslogging/src/main/java/com/yahoo/container/logging/VespaAccessLog.java b/container-accesslogging/src/main/java/com/yahoo/container/logging/VespaAccessLog.java deleted file mode 100644 index 054fc0fcbf7..00000000000 --- a/container-accesslogging/src/main/java/com/yahoo/container/logging/VespaAccessLog.java +++ /dev/null @@ -1,111 +0,0 @@ -// 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 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/container-accesslogging/src/main/java/com/yahoo/container/logging/package-info.java b/container-accesslogging/src/main/java/com/yahoo/container/logging/package-info.java deleted file mode 100644 index fc2abb7b609..00000000000 --- a/container-accesslogging/src/main/java/com/yahoo/container/logging/package-info.java +++ /dev/null @@ -1,5 +0,0 @@ -// 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/container-accesslogging/src/main/resources/configdefinitions/container.core.access-log.def b/container-accesslogging/src/main/resources/configdefinitions/container.core.access-log.def deleted file mode 100644 index 788fadcdf90..00000000000 --- a/container-accesslogging/src/main/resources/configdefinitions/container.core.access-log.def +++ /dev/null @@ -1,17 +0,0 @@ -# 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/container-accesslogging/src/test/java/com/yahoo/container/logging/AccessLogSamplerTest.java b/container-accesslogging/src/test/java/com/yahoo/container/logging/AccessLogSamplerTest.java deleted file mode 100644 index 35664049560..00000000000 --- a/container-accesslogging/src/test/java/com/yahoo/container/logging/AccessLogSamplerTest.java +++ /dev/null @@ -1,63 +0,0 @@ -// 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.net.URI; -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 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/container-accesslogging/src/test/java/com/yahoo/container/logging/CircularArrayAccessLogKeeperTest.java b/container-accesslogging/src/test/java/com/yahoo/container/logging/CircularArrayAccessLogKeeperTest.java deleted file mode 100644 index 5d9509eb045..00000000000 --- a/container-accesslogging/src/test/java/com/yahoo/container/logging/CircularArrayAccessLogKeeperTest.java +++ /dev/null @@ -1,42 +0,0 @@ -// 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/container-accesslogging/src/test/java/com/yahoo/container/logging/CompressWhileDrop.java b/container-accesslogging/src/test/java/com/yahoo/container/logging/CompressWhileDrop.java deleted file mode 100644 index 2099037203f..00000000000 --- a/container-accesslogging/src/test/java/com/yahoo/container/logging/CompressWhileDrop.java +++ /dev/null @@ -1,11 +0,0 @@ -// 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/container-accesslogging/src/test/java/com/yahoo/container/logging/JSONLogTestCase.java b/container-accesslogging/src/test/java/com/yahoo/container/logging/JSONLogTestCase.java deleted file mode 100644 index 6c7878f99ed..00000000000 --- a/container-accesslogging/src/test/java/com/yahoo/container/logging/JSONLogTestCase.java +++ /dev/null @@ -1,276 +0,0 @@ -// 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/container-accesslogging/src/test/java/com/yahoo/container/logging/LogFileHandlerTestCase.java b/container-accesslogging/src/test/java/com/yahoo/container/logging/LogFileHandlerTestCase.java deleted file mode 100644 index bc7257b1ca9..00000000000 --- a/container-accesslogging/src/test/java/com/yahoo/container/logging/LogFileHandlerTestCase.java +++ /dev/null @@ -1,187 +0,0 @@ -// 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/container-accesslogging/src/test/java/com/yahoo/container/logging/test/LogFormatterTestCase.java b/container-accesslogging/src/test/java/com/yahoo/container/logging/test/LogFormatterTestCase.java deleted file mode 100644 index cb34818c35c..00000000000 --- a/container-accesslogging/src/test/java/com/yahoo/container/logging/test/LogFormatterTestCase.java +++ /dev/null @@ -1,27 +0,0 @@ -// 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 java.util.Date; - -import com.yahoo.container.logging.LogFormatter; -import org.junit.Test; - -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); - } - -} diff --git a/container-core/pom.xml b/container-core/pom.xml index 0fbb590a1de..506f5575be4 100644 --- a/container-core/pom.xml +++ b/container-core/pom.xml @@ -39,11 +39,6 @@ org.json json - - com.yahoo.vespa - container-accesslogging - ${project.version} - com.yahoo.vespa defaults diff --git a/container-search/pom.xml b/container-search/pom.xml index 6fa32947869..074f5827122 100644 --- a/container-search/pom.xml +++ b/container-search/pom.xml @@ -65,12 +65,6 @@ json provided - - com.yahoo.vespa - container-accesslogging - ${project.version} - provided - com.yahoo.vespa container-core 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 @@ com.yahoo.vespa - container-accesslogging + security-utils ${project.version} provided com.yahoo.vespa - security-utils + yolean ${project.version} provided com.yahoo.vespa - yolean + vespalog ${project.version} provided + org.apache.httpcomponents @@ -127,6 +128,11 @@ bcpkix-jdk15on test + + org.assertj + assertj-core + test + 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 implementers; + + @Inject + public AccessLog(ComponentRegistry 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; + +/** + *

    Information to be logged in the access log.

    + * + *

    This class contains the union of all information that can be + * logged with all the supported access log formats.

    + * + *

    The add methods can be called multiple times, + * but the parameters should be different for each + * invocation of the same method.

    + * + * 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 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> getKeyValues() { + synchronized (monitor) { + if (keyValues == null) { + return null; + } + + final Map> newMapWithImmutableValues = mapValues( + keyValues.entrySet(), + valueList -> Collections.unmodifiableList(new ArrayList<>(valueList))); + return Collections.unmodifiableMap(newMapWithImmutableValues); + } + } + + private static Map mapValues( + final Set> entrySet, + final Function 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 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 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 getUris() { + final List 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 Steinar Knutsen + */ +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> keyValues = accessLogEntry.getKeyValues(); + if (keyValues != null && !keyValues.isEmpty()) { + generator.writeObjectFieldStart("attributes"); + for (Map.Entry> 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; + +/** + *

    Implements log file naming/rotating logic for container logs.

    + * + *

    Overridden methods: publish

    + * + *

    Added methods: setFilePattern, setRotationTimes, rotateNow (+ few others)

    + * + * @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 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 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 0) { + int newsize = size + (int)moreneeded; + long[] temp = new long[newsize]; + for (i=0; i + *
  • %Y YYYY 2003 + *
  • %m MM 08 + *
  • %x MMM Aug + *
  • %d dd 25 + *
  • %H HH 14 + *
  • %M mm 30 + *
  • %S ss 35 + *
  • %s SSS 123 + *
  • %Z Z -0400 + * + *Others: + *
      + *
    • %T Long.toString(time) + *
    • %% % + *
    + */ + 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 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 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); + } + +} diff --git a/pom.xml b/pom.xml index 762e1829d97..51b044020fa 100644 --- a/pom.xml +++ b/pom.xml @@ -54,7 +54,6 @@ config_test container container-core - container-accesslogging container-dependencies-enforcer container-dependency-versions container-dev -- cgit v1.2.3