diff options
Diffstat (limited to 'container-accesslogging/src')
19 files changed, 2826 insertions, 0 deletions
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 new file mode 100644 index 00000000000..86cdd712031 --- /dev/null +++ b/container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLog.java @@ -0,0 +1,34 @@ +// Copyright 2016 Yahoo Inc. 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; + +import java.net.InetSocketAddress; +import java.net.URI; + +/** + * Logs to all the configured access logs. + * @author tonytv + */ +public class AccessLog { + + private ComponentRegistry<AccessLogInterface> implementers; + + @Inject + public AccessLog(ComponentRegistry<AccessLogInterface> implementers) { + this.implementers = implementers; + } + + public static AccessLog voidAccessLog() { + return new AccessLog(new ComponentRegistry<>()); + } + + public void log(final 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 new file mode 100644 index 00000000000..2e31898fe03 --- /dev/null +++ b/container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLogEntry.java @@ -0,0 +1,711 @@ +// Copyright 2016 Yahoo Inc. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +import java.net.InetAddress; +import java.net.InetSocketAddress; +import java.net.URI; +import java.util.ArrayList; +import java.util.Collections; +import java.util.List; +import java.util.Map; +import java.util.Set; +import java.util.function.Function; +import java.util.logging.Level; +import java.util.logging.Logger; + +import com.yahoo.collections.ListMap; +import org.apache.commons.lang.builder.ReflectionToStringBuilder; + +import static java.util.stream.Collectors.toMap; + +/** + * <p>Information to be logged in the access log.</p> + * + * <p>This class contains the union of all information that can be + * logged with all the supported access log formats.</p> + * + * <p>The add methods can be called multiple times, + * but the parameters should be different for each + * invocation of the same method.</p> + * + * This class is thread-safe, but the inner class {@link AdInfo} is not. + * + * @author tonytv + * @author <a href="mailto:bakksjo@yahoo-inc.com">Oyvind Bakksjo</a> + */ +public class AccessLogEntry { + public enum CookieType { + b, + l, + n, + geocookie, + I, + R, + Y, + M; + } + + // 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 List<AdInfo> adInfos; + private String spaceID; + + private String ipV4AddressInDotDecimalNotation; + private long timeStampMillis; + private long durationBetweenRequestResponseMillis; + private long numBytesReturned; + private URI uri; + + + private String remoteAddress; + private int remotePort; + private String peerAddress; + private int peerPort; + + private CookieType cookieType; + private String cookie; + private String weekOfRegistration; + private String profile; + private String internationalInfo; + private String contentAttribute; + private String webfactsDigitalSignature; + private String errorMessage; + private String fileName; + private String userAgent; + private String referer; + private String user; + private HitCounts hitCounts; + private String requestExtra; + private String responseExtra; + private Boolean resultFromCache; + private String httpMethod; + private String httpVersion; + private String partner; + private String adRationale; + private String incrementSlotByOneRequest; + private String zDataIncrementSlotByOneRequest; + private String hostString; + private int statusCode; + + private ListMap<String,String> keyValues=null; + + public void setCookie( CookieType type, String cookie) { + synchronized (monitor) { + requireNull(this.cookieType); + requireNull(this.cookie); + this.cookieType = type; + this.cookie = cookie; + } + } + + public CookieType getCookieType() { + synchronized (monitor) { + return cookieType; + } + } + + public String getCookie() { + synchronized (monitor) { + return cookie; + } + } + + public void setWeekOfRegistration( String weekOfRegistration ) { + synchronized (monitor) { + requireNull(this.weekOfRegistration); + this.weekOfRegistration = weekOfRegistration; + } + } + + public String getWeekOfRegistration() { + synchronized (monitor) { + return weekOfRegistration; + } + } + + public void setProfile( String profile ) { + synchronized (monitor) { + requireNull(this.profile); + this.profile = profile; + } + } + + public String getProfile() { + synchronized (monitor) { + return profile; + } + } + + public void setInternationalInfo( String intl ) { + synchronized (monitor) { + requireNull(this.internationalInfo); + this.internationalInfo = intl; + } + } + + public String getInternationalInfo() { + synchronized (monitor) { + return internationalInfo; + } + } + + public void setContentAttribute( String contentAttribute ) { + synchronized (monitor) { + requireNull(this.contentAttribute); + this.contentAttribute = contentAttribute; + } + } + + public String getContentAttribute() { + synchronized (monitor) { + return contentAttribute; + } + } + + public void setAdSpaceID(String spaceID) { + synchronized (monitor) { + requireNull(this.spaceID); + this.spaceID = spaceID; + } + } + + public String getAdSpaceID() { + synchronized (monitor) { + return spaceID; + } + } + + public void addAdInfo(AdInfo adInfo) { + synchronized (monitor) { + if (adInfos == null) { + adInfos = new ArrayList<>(); + } + adInfos.add( adInfo ); + } + } + + public List<AdInfo> getAdInfos() { + synchronized (monitor) { + if (adInfos == null) { + return Collections.emptyList(); + } + // TODO: The returned list is unmodifiable, but its elements are not. But we're all friendly here, right? + return Collections.unmodifiableList(adInfos); + } + } + + /** + * This class is NOT thread-safe. It is assumed that a single instance is created/written by a single thread, + * and all reads happen-after creation/population, i.e. no mutation after the instance is shared between threads. + */ + public static class AdInfo { + + private String adServerString; + private String adId; + private String matchId; + private String position; + private String property; + private String cpc; + private String adClientVersion; + private String linkId; + private String bidPosition; + + public void setAdID(String id) { + this.adId = id; + } + + public String getAdID() { + return adId; + } + + public void setMatchID(String id) { + this.matchId = id; + } + + public String getMatchID() { + return matchId; + } + + public void setPosition(String position) { + this.position = position; + } + + public String getPosition() { + return position; + } + + public void setProperty(String property) { + this.property = property; + } + + public String getProperty() { + return property; + } + + public void setCPC(String cpc) { + this.cpc = cpc; + } + + public String getCPC() { + return cpc; + } + + public void setAdClientVersion(String adClientVersion) { + this.adClientVersion = adClientVersion; + } + + public String getAdClientVersion() { + return adClientVersion; + } + + public void setLinkID(String id) { + this.linkId = id; + } + + public String getLinkID() { + return linkId; + } + + public void setBidPosition(String bidPosition) { + this.bidPosition = bidPosition; + } + + public String getBidPosition() { + return bidPosition; + } + + public AdInfo() {} + + AdInfo(String adServerString) { + this.adServerString = adServerString; + } + + String getAdServerString() { + return adServerString; + } + } + + public void setWebfactsDigitalSignature(String signature) { + synchronized (monitor) { + requireNull(this.webfactsDigitalSignature); + this.webfactsDigitalSignature = signature; + } + } + + public String getWebfactsDigitalSignature() { + synchronized (monitor) { + return webfactsDigitalSignature; + } + } + + 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 String getRequestExtra() { + synchronized (monitor) { + return requestExtra; + } + } + + public String getResponseExtra() { + synchronized (monitor) { + return responseExtra; + } + } + + public void addKeyValue(String key,String value) { + synchronized (monitor) { + if (keyValues == null) { + keyValues = new ListMap<>(); + } + keyValues.put(key,value); + } + } + + public Map<String, List<String>> getKeyValues() { + synchronized (monitor) { + if (keyValues == null) { + return null; + } + + final Map<String, List<String>> newMapWithImmutableValues = mapValues( + keyValues.entrySet(), + valueList -> Collections.unmodifiableList(new ArrayList<>(valueList))); + return Collections.unmodifiableMap(newMapWithImmutableValues); + } + } + + private static <K, V1, V2> Map<K, V2> mapValues( + final Set<Map.Entry<K, V1>> entrySet, + final Function<V1, V2> valueConverter) { + return entrySet.stream() + .collect(toMap( + entry -> entry.getKey(), + entry -> valueConverter.apply(entry.getValue()))); + } + + public void setResultFromCache(boolean fromCache) { + synchronized (monitor) { + requireNull(this.resultFromCache); + this.resultFromCache = fromCache; + } + } + + public Boolean getResultFromCache() { + synchronized (monitor) { + return resultFromCache; + } + } + + 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 setPartner(String partner) { + synchronized (monitor) { + requireNull(this.partner); + this.partner = partner; + } + } + + public String getPartner() { + synchronized (monitor) { + return partner; + } + } + + public void setAdRationale(String adRationale) { + synchronized (monitor) { + requireNull(this.adRationale); + this.adRationale = adRationale; + } + } + + public String getAdRationale() { + synchronized (monitor) { + return adRationale; + } + } + + public void setIncrementSlotByOneRequest(String slotName) { + synchronized (monitor) { + requireNull(this.incrementSlotByOneRequest); + this.incrementSlotByOneRequest = slotName; + } + } + + public String getIncrementSlotByOneRequest() { + synchronized (monitor) { + return incrementSlotByOneRequest; + } + } + + public void setZDataIncrementSlotByOneRequest(String slotName) { + synchronized (monitor) { + requireNull(this.zDataIncrementSlotByOneRequest); + this.zDataIncrementSlotByOneRequest = slotName; + } + } + + public String getZDataIncrementSlotByOneRequest() { + synchronized (monitor) { + return zDataIncrementSlotByOneRequest; + } + } + + 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 setURI(final URI uri) { + synchronized (monitor) { + requireNull(this.uri); + this.uri = uri; + } + } + + public URI getURI() { + synchronized (monitor) { + return uri; + } + } + + 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; + } + } + + @Override + public String toString() { + synchronized (monitor) { + return new ReflectionToStringBuilder(this) + .setExcludeFieldNames(FIELDS_EXCLUDED_FROM_TOSTRING) + .toString(); + } + } + + 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 new file mode 100644 index 00000000000..27a5cf9e827 --- /dev/null +++ b/container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLogHandler.java @@ -0,0 +1,52 @@ +// Copyright 2016 Yahoo Inc. 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 static com.yahoo.container.core.AccessLogConfig.FileHandler.RotateScheme.DATE; + +import java.util.logging.Logger; + +/** + * @author <a href="mailto:borud@yahoo-inc.com">Bjorn Borud</a> + */ +class AccessLogHandler { + + public Logger access = Logger.getAnonymousLogger(); + private LogFileHandler logFileHandler; + + public AccessLogHandler(AccessLogConfig.FileHandler config) { + access.setUseParentHandlers(false); + + logFileHandler = new LogFileHandler(config.rotateScheme()); + + logFileHandler.setFilePattern(config.pattern()); + logFileHandler.setRotationTimes(config.rotation()); + + if (config.rotateScheme() == DATE) + 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 new file mode 100644 index 00000000000..674f5883c03 --- /dev/null +++ b/container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLogInterface.java @@ -0,0 +1,9 @@ +// Copyright 2016 Yahoo Inc. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +/** + * @author tonytv + */ +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 new file mode 100644 index 00000000000..987035bb0e9 --- /dev/null +++ b/container-accesslogging/src/main/java/com/yahoo/container/logging/AccessLogSampler.java @@ -0,0 +1,37 @@ +// Copyright 2016 Yahoo Inc. 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 dybdahl + */ +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.getURI().toString(); + 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 new file mode 100644 index 00000000000..7a60eb2098c --- /dev/null +++ b/container-accesslogging/src/main/java/com/yahoo/container/logging/CircularArrayAccessLogKeeper.java @@ -0,0 +1,48 @@ +// Copyright 2016 Yahoo Inc. 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 dybdahl + */ +public class CircularArrayAccessLogKeeper { + public static final int SIZE = 1000; + private final Deque<String> uris = new ArrayDeque<>(SIZE); + private final Object monitor = new Object(); + + /** + * This class is intended to be used with injection so it can be shared between other classes. + */ + public CircularArrayAccessLogKeeper() {} + + /** + * Creates a list of Uris. + * @return URIs as string + */ + public List<String> getUris() { + final List<String> uriList = new ArrayList<>(); + synchronized (monitor) { + uris.iterator().forEachRemaining(uri -> uriList.add(uri)); + } + return uriList; + } + + /** + * Add a new URI. It might remove an old entry to make space for new entry. + * @param uri uri as string + */ + public void addUri(String uri) { + synchronized (monitor) { + if (uris.size() == SIZE) { + uris.pop(); + } + uris.add(uri); + } + } +} diff --git a/container-accesslogging/src/main/java/com/yahoo/container/logging/HitCounts.java b/container-accesslogging/src/main/java/com/yahoo/container/logging/HitCounts.java new file mode 100644 index 00000000000..f403308a404 --- /dev/null +++ b/container-accesslogging/src/main/java/com/yahoo/container/logging/HitCounts.java @@ -0,0 +1,72 @@ +// Copyright 2016 Yahoo Inc. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +/** + * A wrapper for hit counts, modelled after a search system. + * Advanced database searches and similar could use these + * structures as well. + * + * @author <a href="mailto:steinar@yahoo-inc.com">Steinar Knutsen</a> + */ +public class HitCounts { + + // see the javadoc for the accessors for short comments on each field + private final int retrievedHits; + private final int summaryCount; + private final long totalHitCount; + private final int requestedHits; + private final int requestedOffset; + + public HitCounts( + int retrievedHits, + int summaryCount, + long totalHitCount, + int requestedHits, + int requestedOffset) { + + this.retrievedHits = retrievedHits; + this.summaryCount = summaryCount; + this.totalHitCount = totalHitCount; + this.requestedHits = requestedHits; + this.requestedOffset = requestedOffset; + } + + /** + * 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; + } + +} 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 new file mode 100644 index 00000000000..5e86c55c294 --- /dev/null +++ b/container-accesslogging/src/main/java/com/yahoo/container/logging/LogFileHandler.java @@ -0,0 +1,363 @@ +// Copyright 2016 Yahoo Inc. 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.io.File; +import java.io.FileOutputStream; +import java.io.IOException; +import java.io.OutputStream; +import java.util.ArrayList; +import java.util.concurrent.ArrayBlockingQueue; +import java.util.logging.Formatter; +import java.util.logging.Level; +import java.util.logging.LogRecord; +import java.util.logging.StreamHandler; +import java.util.regex.Matcher; +import java.util.regex.Pattern; + + +/** + * <p>Implements log file naming/rotating logic for container logs.</p> + * + * <p>Overridden methods: publish</p> + * + * <p>Added methods: setFilePattern, setRotationTimes, rotateNow (+ few others)</p> + * + * @author Bob Travis + */ +public class LogFileHandler extends StreamHandler { + + /** True to use the sequence file name scheme, false (default) to use the date scheme */ + private final boolean useSequenceNameScheme; + 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 lastRotationTime = -1; // absolute time (millis since epoch) of current file start + private int numberOfRecords = -1; + private long nextRotationTime = 0; + private OutputStream currentOutputStream = null; + private String fileName; + private String symlinkName = null; + private ArrayBlockingQueue<LogRecord> logQueue = new ArrayBlockingQueue<>(1000); + LogRecord rotateCmd = new LogRecord(Level.SEVERE, "rotateNow"); + + static private class LogThread extends Thread { + LogFileHandler logFileHandler; + public LogThread(LogFileHandler logFile) { + super("Logger"); + 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.take(); + if (r == logFileHandler.rotateCmd) { + logFileHandler.internalRotateNow(); + } else { + logFileHandler.internalPublish(r); + } + } + } + } + LogThread logThread = null; + + public LogFileHandler() { + this(AccessLogConfig.FileHandler.RotateScheme.Enum.DATE); + } + + public LogFileHandler(AccessLogConfig.FileHandler.RotateScheme.Enum rotateScheme) { + super(); + this.useSequenceNameScheme = rotateScheme == AccessLogConfig.FileHandler.RotateScheme.Enum.SEQUENCE; + init(); + } + + /** + * Constructs a log handler + * + * @param useSequenceNameScheme True to use the sequence file name scheme, false (default) to use the date scheme + */ + public LogFileHandler(OutputStream out, Formatter formatter,boolean useSequenceNameScheme) { + super(out,formatter); + this.useSequenceNameScheme=useSequenceNameScheme; + init(); + } + + private void init() { + 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) { + } + } + + private void internalPublish(LogRecord r) throws InterruptedException { + // 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(); + } + // count records, and publish + numberOfRecords++; + super.publish(r); + flush(); + } + + /** + * Assign pattern for generating (rotating) file names. + * + * @param pattern See LogFormatter for definition + */ + public void setFilePattern ( String pattern ) { + filePattern = pattern; + } + + /** + * Assign times for rotating output files. + * + * @param timesOfDay in millis, from midnight + * + */ + public void setRotationTimes ( long[] timesOfDay ) { + rotationTimes = timesOfDay; + } + + /** Assign time for rotating output files + * + * @param prescription string form of times, in minutes + */ + public 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 + */ + public long getNextRotationTime (long now) { + if (now <= 0) { + now = System.currentTimeMillis(); + } + long nowTod = timeOfDayMillis(now); + long next = 0; + for (int i = 0; i<rotationTimes.length; i++) { + if (nowTod < rotationTimes[i]) { + next = rotationTimes[i]-nowTod + now; + break; + } + } + if (next == 0) { // didn't find one -- use 1st time 'tomorrow' + next = rotationTimes[0]+lengthOfDayMillis-nowTod + now; + } + + return next; + } + + private void checkAndCreateDir(String pathname) throws IOException { + 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. + */ + public void rotateNow () { + publish(rotateCmd); + } + + // Throw InterruptedException upwards rather than relying on isInterrupted to stop the thread as + // isInterrupted() returns false after inerruption in p.waitFor + private void internalRotateNow() throws InterruptedException { + // figure out new file name, then + // use super.setOutputStream to switch to a new file + + long now = System.currentTimeMillis(); + fileName = LogFormatter.insertDate(filePattern, now); + super.flush(); + super.close(); + + if (useSequenceNameScheme) + moveCurrentFile(); + + try { + checkAndCreateDir(fileName); + FileOutputStream os = new FileOutputStream(fileName, true); // append mode, for safety + super.setOutputStream(os); + currentOutputStream = os; + } + catch (IOException e) { + throw new RuntimeException("Couldn't open log file '" + fileName + "'", e); + } + + if ( ! useSequenceNameScheme) + createSymlinkToCurrentFile(); + + numberOfRecords = 0; + lastRotationTime = now; + nextRotationTime = 0; //figure it out later (lazy evaluation) + } + + /** Name files by date - create a symlink with a constant name to the newest file */ + private void createSymlinkToCurrentFile() throws InterruptedException { + if (symlinkName == null) return; + File f = new File(fileName); + File f2 = new File(f.getParent(), symlinkName); + try { + Runtime r = Runtime.getRuntime(); + Process p = r.exec(new String[] { "/bin/ln", "-sf", f.getCanonicalPath(), f2.getPath() }); + // 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 + p.waitFor(); + } catch (IOException e) { + // little we can do... + } + } + + /** + * Name the current file to "name.n" where n + * 1+ the largest integer in existing file names + */ + private void moveCurrentFile() { + File file=new File(fileName); + if ( ! file.exists()) return; // no current file + File dir=file.getParentFile(); + Pattern logFilePattern=Pattern.compile(".*\\.(\\d+)"); + long largestN=0; + for (File existingFile : dir.listFiles()) { + Matcher matcher=logFilePattern.matcher(existingFile.getName()); + if (!matcher.matches()) continue; + long thisN=Long.parseLong(matcher.group(1)); + if (thisN>largestN) + largestN=thisN; + } + file.renameTo(new File(dir,file.getName() + "." + (largestN + 1))); + } + + /** + * @return last time file rotation occurred for this output file + */ + public long getLastRotationTime () { + return lastRotationTime; + } + + /** + * @return number of records written to this file since last rotation + */ + public long getNumberRecords () { + return numberOfRecords; + } + + /** + * Calculate rotation times array, given times in minutes, as "0 60 ..." + * + */ + public static long[] calcTimesMinutes(String times) { + ArrayList<Long> list = new ArrayList<>(50); + int i = 0; + boolean etc = false; + + while (i < times.length()) { + if (times.charAt(i) == ' ') { i++; continue; } // skip spaces + int j = i; // start of string + i = times.indexOf(' ', i); + if (i == -1) i = times.length(); + if (times.charAt(j) == '.' && times.substring(j,i).equals("...")) { // ... + etc = true; + break; + } + list.add(new Long(times.substring(j,i))); + } + + int size = list.size(); + long[] longtimes = new long[size]; + for (i = 0; i<size; i++) { + longtimes[i] = list.get(i).longValue() // pick up value in minutes past midnight + * 60000; // and multiply to get millis + } + + if (etc) { // fill out rest of day, same as final interval + long endOfDay = 24*60*60*1000; + long lasttime = longtimes[size-1]; + long interval = lasttime - longtimes[size-2]; + long moreneeded = (endOfDay - lasttime)/interval; + if (moreneeded > 0) { + int newsize = size + (int)moreneeded; + long[] temp = new long[newsize]; + for (i=0; i<size; i++) { + temp[i] = longtimes[i]; + } + while (size < newsize) { + lasttime += interval; + temp[size++] = lasttime; + } + longtimes = temp; + } + } + + return longtimes; + } + + // Support staff :-) + private static final long lengthOfDayMillis = 24*60*60*1000; // ? is this close enough ? + + private static final long timeOfDayMillis ( long time ) { + return time % lengthOfDayMillis; + } + + public void setSymlinkName(String symlinkName) { + this.symlinkName = symlinkName; + } + + /** + * Flushes all queued messages, interrupts the log thread in this and + * waits for it to end before returning + */ + public void shutdown() { + logThread.interrupt(); + try { + logThread.join(); + } + catch (InterruptedException e) { + } + } + + /** + * Only for unit testing. Do not use. + */ + public String getFileName() { + return fileName; + } + +} diff --git a/container-accesslogging/src/main/java/com/yahoo/container/logging/LogFormatter.java b/container-accesslogging/src/main/java/com/yahoo/container/logging/LogFormatter.java new file mode 100644 index 00000000000..961bfc32cc1 --- /dev/null +++ b/container-accesslogging/src/main/java/com/yahoo/container/logging/LogFormatter.java @@ -0,0 +1,190 @@ +// Copyright 2016 Yahoo Inc. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +import java.text.DateFormat; +import java.text.SimpleDateFormat; +import java.util.Date; +import java.util.TimeZone; +import java.util.logging.Formatter; +import java.util.logging.LogRecord; + + +/** + * Produces compact output format for prelude logs + * + * @author Bob Travis + */ +public class LogFormatter extends Formatter { + + /** date format objects */ + static SimpleDateFormat ddMMMyyyy; + static DateFormat dfMMM; + static SimpleDateFormat yyyyMMdd; + + static { + ddMMMyyyy = new SimpleDateFormat("[dd/MMM/yyyy:HH:mm:ss Z]"); + ddMMMyyyy.setTimeZone(TimeZone.getTimeZone("UTC")); + + dfMMM = new SimpleDateFormat("MMM"); + dfMMM.setTimeZone(TimeZone.getTimeZone("UTC")); + + yyyyMMdd = new SimpleDateFormat("[yyyy-MM-dd HH:mm:ss]"); + yyyyMMdd.setTimeZone(TimeZone.getTimeZone("UTC")); + } + + /** Whether to strip down the message to only the message or not */ + private boolean messageOnly = false; + + /** Controls which of the available timestamp formats is used in all log records + */ + private static final int timestampFormat = 2; // 0=millis, 1=mm/dd/yyyy, 2=yyyy-mm-dd + + /** + * Standard constructor + */ + + public LogFormatter() {} + + /** + * Make it possible to log stripped messages + */ + public void messageOnly (boolean messageOnly) { + this.messageOnly = messageOnly; + } + + public String format(LogRecord record) { + + // if we don't want any other stuff we just return the message + if (messageOnly) { + return formatMessage(record); + } + + String rawMsg = record.getMessage(); + boolean isLogMsg = + rawMsg.charAt(0) == 'L' + && rawMsg.charAt(1) == 'O' + && rawMsg.charAt(2) == 'G' + && rawMsg.charAt(3) == ':'; + String nameInsert = + (!isLogMsg) + ? record.getLevel().getName() + ": " + : ""; + return (timeStamp(record) + + nameInsert + + formatMessage(record) + + "\n" + ); + } + + /** + * Public support methods + */ + + /** + * Static insertDate method will insert date fragments into a string + * based on '%x' pattern elements. Equivalents in SimpleDateFormatter patterns, + * with examples: + * <ul> + * <li>%Y YYYY 2003 + * <li>%m MM 08 + * <li>%x MMM Aug + * <li>%d dd 25 + * <li>%H HH 14 + * <li>%M mm 30 + * <li>%S ss 35 + * <li>%s SSS 123 + * <li>%Z Z -0400 + * </ul> + *Others: + * <ul> + * <li>%T Long.toString(time) + * <li>%% % + * </ul> + */ + public static final String insertDate (String pattern, long time) { + DateFormat df = new SimpleDateFormat("yyyy.MM.dd:HH:mm:ss.SSS Z"); + 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/VespaAccessLog.java b/container-accesslogging/src/main/java/com/yahoo/container/logging/VespaAccessLog.java new file mode 100644 index 00000000000..566cf17f89f --- /dev/null +++ b/container-accesslogging/src/main/java/com/yahoo/container/logging/VespaAccessLog.java @@ -0,0 +1,115 @@ +// Copyright 2016 Yahoo Inc. 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 com.yahoo.net.UriTools; + +import java.net.URI; +import java.text.SimpleDateFormat; +import java.util.Date; +import java.util.TimeZone; +import java.util.logging.Level; + +/** + * @author <a href="mailto:borud@yahoo-inc.com">Bjorn Borud</a> + * @author <a href="mailto:bakksjo@yahoo-inc.com">Oyvind Bakksjo</a> + */ +public final class VespaAccessLog implements AccessLogInterface { + + private static final SimpleDateFormat dateFormat = 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 String getDate () { + Date date = new Date(); + return dateFormat.format(date); + } + + private String getRequest(final String httpMethod, final URI uri, final String httpVersion) { + final URI normalizedUri = uri.normalize(); + return httpMethod + " " + UriTools.rawRequest(normalizedUri) + " " + httpVersion; + } + + private String getUser(String user) { + return (user == null) ? "-" : user; + } + + private void writeLog(String ipAddr, String user, String request, String referer, String agent, long startTime, + 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.getURI(), + accessLogEntry.getHttpVersion()), + accessLogEntry.getReferer(), + accessLogEntry.getUserAgent(), + accessLogEntry.getTimeStampMillis(), + accessLogEntry.getDurationBetweenRequestResponseMillis(), + accessLogEntry.getReturnedContentSize(), + accessLogEntry.getHitCounts(), + accessLogEntry.getStatusCode()); + } +} diff --git a/container-accesslogging/src/main/java/com/yahoo/container/logging/YApacheAccessLog.java b/container-accesslogging/src/main/java/com/yahoo/container/logging/YApacheAccessLog.java new file mode 100644 index 00000000000..127368049c4 --- /dev/null +++ b/container-accesslogging/src/main/java/com/yahoo/container/logging/YApacheAccessLog.java @@ -0,0 +1,36 @@ +// Copyright 2016 Yahoo Inc. 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 yApache log format. + * + * @author tinyv + */ +public final class YApacheAccessLog implements AccessLogInterface { + + private final AccessLogHandler logHandler; + + public YApacheAccessLog(AccessLogConfig config) { + logHandler = new AccessLogHandler(config.fileHandler()); + } + + @Override + public void log(final AccessLogEntry logEntry) { + logHandler.access.log(Level.INFO, new YApacheFormatter(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/YApacheFormatter.java b/container-accesslogging/src/main/java/com/yahoo/container/logging/YApacheFormatter.java new file mode 100644 index 00000000000..ec19e909614 --- /dev/null +++ b/container-accesslogging/src/main/java/com/yahoo/container/logging/YApacheFormatter.java @@ -0,0 +1,470 @@ +// Copyright 2016 Yahoo Inc. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.container.logging; + +import java.net.URI; +import java.util.Formatter; +import java.util.HashMap; +import java.util.Iterator; +import java.util.List; +import java.util.Map; +import java.util.Objects; +import java.util.logging.Level; +import java.util.logging.Logger; + +import static com.yahoo.container.logging.AccessLogEntry.CookieType; + +/** + * Formatting of an {@link AccessLogEntry} in the yapache access log format. + * + * @author tonytv + * @author bakksjo + */ +public class YApacheFormatter { + + private AccessLogEntry accessLogEntry; + + public YApacheFormatter(final AccessLogEntry entry) { + accessLogEntry = entry; + } + + public String format() { + // Initial 32-byte fixed block of mandatory, non-prefixed fields. + setIpV4Address(accessLogEntry.getIpV4Address()); + setTimeStampMillis(accessLogEntry.getTimeStampMillis()); + setDurationBetweenRequestResponseMillis(accessLogEntry.getDurationBetweenRequestResponseMillis()); + setReturnedContentSize(accessLogEntry.getReturnedContentSize()); + + // Optional, prefixed fields in arbitrary order. + setStatusCode(accessLogEntry.getStatusCode()); + setRemoteAddress(accessLogEntry.getRemoteAddress()); + setRemotePort(accessLogEntry.getRemotePort()); + setURI(accessLogEntry.getURI()); + setCookie(accessLogEntry.getCookieType(), accessLogEntry.getCookie()); + setWeekOfRegistration(accessLogEntry.getWeekOfRegistration()); + setProfile(accessLogEntry.getProfile()); + setInternationalInfo(accessLogEntry.getInternationalInfo()); + setContentAttribute(accessLogEntry.getContentAttribute()); + setAdSpaceID(accessLogEntry.getAdSpaceID()); + setErrorMessage(accessLogEntry.getErrorMessage()); + setFileName(accessLogEntry.getFileName()); + setUserAgent(accessLogEntry.getUserAgent()); + setWebfactsDigitalSignature(accessLogEntry.getWebfactsDigitalSignature()); + setReferer(accessLogEntry.getReferer()); + setRequestExtra(accessLogEntry.getRequestExtra()); + setResponseExtra(accessLogEntry.getResponseExtra()); + setResultFromCache(accessLogEntry.getResultFromCache()); + setHttpMethod(accessLogEntry.getHttpMethod()); + setPartner(accessLogEntry.getPartner()); + setAdRationale(accessLogEntry.getAdRationale()); + setIncrementSlotByOneRequest(accessLogEntry.getIncrementSlotByOneRequest()); + setZDataIncrementSlotByOneRequest(accessLogEntry.getZDataIncrementSlotByOneRequest()); + setHostString(accessLogEntry.getHostString()); + setPeerAddress(accessLogEntry.getPeerAddress()); + setPeerPort(accessLogEntry.getPeerPort()); + adInfos = accessLogEntry.getAdInfos(); + keyValues = accessLogEntry.getKeyValues(); + + return toYApacheAccessEntry(); + } + + private static final Map<CookieType, Character> cookieTypeFirstCharMap = new HashMap<>(); + static { + cookieTypeFirstCharMap.put(CookieType.b, '1'); + cookieTypeFirstCharMap.put(CookieType.l, '2'); + cookieTypeFirstCharMap.put(CookieType.n, '3'); + cookieTypeFirstCharMap.put(CookieType.geocookie,'5'); + cookieTypeFirstCharMap.put(CookieType.I, '7'); + cookieTypeFirstCharMap.put(CookieType.R, '9'); + cookieTypeFirstCharMap.put(CookieType.Y, 'c'); + cookieTypeFirstCharMap.put(CookieType.M, 'M'); + } + + private List<AccessLogEntry.AdInfo> adInfos; + private String spaceID; + + private String ipV4AddressInDotDecimalNotation; + private String unixTimeStamp; + private String durationBetweenRequestResponseInMS; + private String numBytesReturned; + private String uri; + + + private String remoteAddress; + private int remotePort; + private String peerAddress; + private int peerPort; + + private Map<String,List<String>> keyValues; + + private static Logger logger = Logger.getLogger(YApacheFormatter.class.getName()); + + private void setCookie(CookieType type, String cookie) { + final Character firstChar = cookieTypeFirstCharMap.get(type); + if (firstChar == null) { + return; + } + addField(firstChar, cookie); + } + + private void setWeekOfRegistration( String weekOfRegistration ) { + addField('4', weekOfRegistration); + } + + private void setProfile( String profile ) { + addField('6', profile); + } + + private void setInternationalInfo( String intl ) { + addField('8', intl); + } + + private void setContentAttribute( String contentAttribute ) { + addField('a', contentAttribute); + } + + private void setAdSpaceID(String spaceID) { + this.spaceID = spaceID; + } + + private static class AdInfo { + + private void setAdID(String id) { + add('B', id); + } + + private void setMatchID(String id) { + add('C', id); + } + + private void setPosition(String position) { + add('D', position); + } + + private void setProperty(String property) { + add('F', property); + } + + private void setCPC(String cpc) { + add('G', cpc); + } + + private void setAdClientVersion(String adClientVersion) { + add('K', adClientVersion); + } + + private void setLinkID(String id) { + add('L', id); + } + + private void setBidPosition(String bidPosition) { + add('P', bidPosition); + } + + private StringBuilder adInfo = new StringBuilder(); + + AdInfo(final AccessLogEntry.AdInfo model) { + final String modelAdServerString = model.getAdServerString(); + if (modelAdServerString != null) { + adInfo.append(modelAdServerString); + } + setAdID(model.getAdID()); + setMatchID(model.getMatchID()); + setPosition(model.getPosition()); + setProperty(model.getProperty()); + setCPC(model.getCPC()); + setAdClientVersion(model.getAdClientVersion()); + setLinkID(model.getLinkID()); + setBidPosition(model.getBidPosition()); + } + + String adInfoString() { + return adInfo.toString(); + } + + private void add(char controlChar, String value) { + if (value == null) { + return; + } + adInfo.append( controlCharacter(controlChar) ); + adInfo.append( value ); + } + } + + private void setWebfactsDigitalSignature(String signature) { + addField('d', signature); + } + + private void setErrorMessage(String errorMessage) { + addField('e', errorMessage); + } + + private void setFileName(String fileName) { + addField('f', fileName); + } + + private void setUserAgent(String userAgent) { + addField('g', userAgent); + } + + private void setReferer(String referer) { + addField('r', referer); + } + + private void setRequestExtra(String requestExtra) { + if (requestExtra == null || requestExtra.isEmpty()) { + return; + } + if (fieldPrefix != requestExtra.charAt(0)) { + yApacheEntry.append(fieldPrefix); + } + yApacheEntry.append(requestExtra); + } + + private void setResponseExtra(String responseExtra) { + if (responseExtra == null || responseExtra.isEmpty()) { + return; + } + if (fieldPrefix != responseExtra.charAt(0)) { + yApacheEntry.append(fieldPrefix); + } + yApacheEntry.append(responseExtra); + } + + private void setResultFromCache(Boolean fromCache) { + if (fromCache == null) { + return; + } + addField('h', + fromCache ? "1" : "0"); + } + + private void setHttpMethod(String method) { + addField('m', method); + } + + private void setPartner(String partner) { + addField('p', partner); + } + + private void setAdRationale(String adRationale) { + addField('R', adRationale); + } + + private void setIncrementSlotByOneRequest(String slotName) { + addField('t', slotName); + } + + private void setZDataIncrementSlotByOneRequest(String slotName) { + addField('z', slotName); + } + + private void setHostString(String hostString) { + addField('w', hostString); + } + + private StringBuilder yApacheEntry = new StringBuilder(); + + private static char fieldPrefix = controlCharacter('E'); + private static char valueSeparator = controlCharacter('A'); + + + //assumes A <= c <= Z + private static char controlCharacter(char c) { + return (char)((c - 'A') + 1); + } + + private void appendStartOfField(StringBuilder builder, char firstChar) { + builder.append(fieldPrefix); + builder.append(firstChar); + } + + private void addField(char firstChar, String field) { + if (field == null) { + return; + } + appendStartOfField(yApacheEntry, firstChar); + yApacheEntry.append(field); + } + + private void addDecimalField(char firstChar, int field) { + addField(firstChar, Integer.toString(field)); + } + + private String to8ByteHexString(final long value) { + Formatter formatter = new Formatter(); + formatter.format("%08x", value); + return formatter.toString(); + } + + private void appendAdInfo(StringBuilder buf) { + if (spaceID != null || ! adInfos.isEmpty()) { + buf.append(fieldPrefix); + buf.append('b'); + + if (spaceID != null) { + buf.append( controlCharacter('A') ); + buf.append( spaceID ); + } + + for (AccessLogEntry.AdInfo adInfo : adInfos ) { + buf.append( new AdInfo(adInfo).adInfoString() ); + } + } + } + + private void appendFirst32Bytes(StringBuilder buf) { + buf.append(ipv4AddressToHexString(ipV4AddressInDotDecimalNotation)); + buf.append(unixTimeStamp); + buf.append(durationBetweenRequestResponseInMS); + buf.append(numBytesReturned); + + assert(buf.length() == 32); + } + + private String toYApacheAccessEntry() { + StringBuilder b = new StringBuilder(); + + appendFirst32Bytes(b); + b.append(uri); + + b.append(yApacheEntry); + appendIPv6AddressInfo(b); + appendAdInfo(b); + + appendKeyValues(b); + return b.toString(); + } + + private void appendIPv6AddressInfo(StringBuilder builder) { + appendStartOfField(builder, 'A'); + final boolean remoteAddressesAreEqual = Objects.equals(ipV4AddressInDotDecimalNotation, remoteAddress); + if (!remoteAddressesAreEqual && remoteAddress != null) { + builder.append('A').append(remoteAddress).append(valueSeparator); + } + + builder.append('B').append(remotePort); + + if (peerAddress != null) { + builder.append(valueSeparator).append('C').append(peerAddress); + } + + if (peerPort > 0 && peerPort != remotePort) { + builder.append(valueSeparator).append('D').append(peerPort); + } + } + + /** + * Encodes key-values added to this entry at the "property extension" key 'X' as + * <code>^EY[key1]^F[value1.1]^B[value1.2]^A[key2]^F[value2]</code>, + */ + private void appendKeyValues(StringBuilder b) { + if (keyValues==null) return; + b.append(fieldPrefix); + b.append('X'); + for (Map.Entry<String,List<String>> entry : keyValues.entrySet()) { + b.append(entry.getKey()); + b.append(controlCharacter('F')); + for (Iterator<String> i=entry.getValue().iterator(); i.hasNext(); ) { + b.append(i.next()); + if (i.hasNext()) + b.append(controlCharacter('B')); + } + b.append(controlCharacter('A')); + } + b.deleteCharAt(b.length()-1); // Deletes the last ^A to be able to do foreach looping :-) + } + + private String ipv4AddressToHexString(String ipv4AddressInDotDecimalNotation) { + try { + String[] parts = ipv4AddressInDotDecimalNotation.split("\\."); + if (parts.length != 4) { + throw new Exception(); + } else { + Formatter byteHexFormatter = new Formatter(); + + for (String part : parts) { + int i = Integer.parseInt(part); + if ( i > 0xff || i < 0) + throw new Exception(); + byteHexFormatter.format("%02x", i); + } + + return byteHexFormatter.toString(); + } + } catch( Exception e ) { + logger.log(Level.WARNING, "IPv4 address not in dot decimal notation: " + + ipv4AddressInDotDecimalNotation); + return "00000000"; + } + } + + private void setIpV4Address(String ipV4AddressInDotDecimalNotation) { + this.ipV4AddressInDotDecimalNotation = ipV4AddressInDotDecimalNotation; + } + + private void setTimeStampMillis(long numMillisSince1Jan1970AtMidnightUTC) { + int unixTime = (int)(numMillisSince1Jan1970AtMidnightUTC/1000); + + if (numMillisSince1Jan1970AtMidnightUTC/1000 > 0x7fffffff) { + logger.log(Level.WARNING, "A year 2038 problem occurred."); + logger.log(Level.INFO, "numMillisSince1Jan1970AtMidnightUTC: " + + numMillisSince1Jan1970AtMidnightUTC); + unixTime = (int)(numMillisSince1Jan1970AtMidnightUTC/1000 % 0x7fffffff); + } + + unixTimeStamp = to8ByteHexString(unixTime); + } + + private void setDurationBetweenRequestResponseMillis(long timeInMillis) { + long timeInMicroSeconds = timeInMillis*1000; + if (timeInMicroSeconds > 0xffffffffL) { + logger.log(Level.WARNING, "Duration too long: " + timeInMillis); + timeInMicroSeconds = 0xffffffffL; + } + + durationBetweenRequestResponseInMS = to8ByteHexString(timeInMicroSeconds); + } + + private void setReturnedContentSize(long byteCount) { + numBytesReturned = to8ByteHexString(byteCount); + } + + private void setURI(final URI uri) { + setNormalizedURI(uri.normalize()); + } + + private void setNormalizedURI(final URI normalizedUri) { + String uriString = normalizedUri.getPath(); + if (normalizedUri.getRawQuery() != null) { + uriString = uriString + "?" + normalizedUri.getRawQuery(); + } + + this.uri = uriString; + } + + private void setRemoteAddress(String remoteAddress) { + this.remoteAddress = remoteAddress; + } + + private void setRemotePort(int remotePort) { + this.remotePort = remotePort; + } + + private void setPeerAddress(final String peerAddress) { + this.peerAddress = peerAddress; + } + + private void setPeerPort(int peerPort) { + this.peerPort = peerPort; + } + + /** Sets the status code, which will end up in the "s" field. If this is 200 the field is not written (by spec). */ + private void setStatusCode(int statusCode) { + if (statusCode == 0) { + return; + } + if (statusCode!=200) + addDecimalField('s', statusCode); + } + +} 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 new file mode 100644 index 00000000000..e2c1f7c0bb7 --- /dev/null +++ b/container-accesslogging/src/main/java/com/yahoo/container/logging/package-info.java @@ -0,0 +1,5 @@ +// Copyright 2016 Yahoo Inc. 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/access-log.def b/container-accesslogging/src/main/resources/configdefinitions/access-log.def new file mode 100644 index 00000000000..0e09e2a1fb7 --- /dev/null +++ b/container-accesslogging/src/main/resources/configdefinitions/access-log.def @@ -0,0 +1,28 @@ +# Copyright 2016 Yahoo Inc. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +version=2 +namespace=container.core + + +# File name patterns supporting the expected time variables, e.g. ".%Y%m%d%H%M%S" +fileHandler.pattern string +fileHandler.rotation string default="0 60 ..." + +# Defines how file rotation is done. There are two options: +# +# DATE: +# The active log file is given the name resulting from pattern (but in this case "pattern" must yield a +# time-dependent name. In addition, a symlink is created pointing to the newest file. +# The symlink is given the name of the symlink parameter (or the name of this service +# if no parameter is given. +# +# SEQUENCE: +# The active log file is given the name +# defined by "pattern" (which in this case will likely just be a constant string). +# At rotation, this file is given the name pattern.N where N is 1 + the largest integer found by +# extracting the integers from all files ending by .Integer in the same directory +# +fileHandler.rotateScheme enum {DATE, SEQUENCE} default=DATE + +# 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="" 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 new file mode 100644 index 00000000000..33a4935d223 --- /dev/null +++ b/container-accesslogging/src/test/java/com/yahoo/container/logging/AccessLogSamplerTest.java @@ -0,0 +1,63 @@ +// Copyright 2016 Yahoo Inc. 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<String> uris = new ArrayList<>(); + private CircularArrayAccessLogKeeper circularArrayAccessLogKeeperMock = new CircularArrayAccessLogKeeper() { + @Override + public void addUri(String uri) { + uris.add(uri); + } + }; + private AccessLogSampler accessLogSampler = new AccessLogSampler(circularArrayAccessLogKeeperMock); + + @Test + public void testAFewLines() { + accessLogSampler.log(createLogEntry(200, "/search/foo")); + accessLogSampler.log(createLogEntry(500, "/search/bar")); + accessLogSampler.log(createLogEntry(500, "bar")); + accessLogSampler.log(createLogEntry(200, "/search/what")); + assertThat(uris, contains("/search/foo", "/search/what")); + } + + @Test + public void testSubSampling() { + for (int i = 0; i < CircularArrayAccessLogKeeper.SIZE; i++) { + accessLogSampler.log(createLogEntry(200, "/search/" + String.valueOf(i))); + } + assertThat(uris.size(), is(CircularArrayAccessLogKeeper.SIZE)); + assertThat(uris, hasItems("/search/0", "/search/1", "/search/2", + "/search/" + String.valueOf(CircularArrayAccessLogKeeper.SIZE - 1))); + uris.clear(); + for (int i = 0; i < CircularArrayAccessLogKeeper.SIZE; i++) { + accessLogSampler.log(createLogEntry(200, "/search/fuzz")); + } + assertThat(uris, hasItem("/search/fuzz")); + assertThat(uris.size(), is(1)); + for (int i = 0; i < CircularArrayAccessLogKeeper.SIZE; i++) { + accessLogSampler.log(createLogEntry(200, "/search/ball")); + } + assertThat(uris, hasItem("/search/ball")); + assertThat(uris.size(), is(2)); + } + + private AccessLogEntry createLogEntry(int statusCode, String uri) { + AccessLogEntry accessLogEntry = new AccessLogEntry(); + accessLogEntry.setStatusCode(statusCode); + accessLogEntry.setURI(URI.create(uri)); + return accessLogEntry; + } +}
\ No newline at end of file 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 new file mode 100644 index 00000000000..d872f62ea82 --- /dev/null +++ b/container-accesslogging/src/test/java/com/yahoo/container/logging/CircularArrayAccessLogKeeperTest.java @@ -0,0 +1,42 @@ +// Copyright 2016 Yahoo Inc. 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")); + } +}
\ No newline at end of file diff --git a/container-accesslogging/src/test/java/com/yahoo/container/logging/YApacheLogTestCase.java b/container-accesslogging/src/test/java/com/yahoo/container/logging/YApacheLogTestCase.java new file mode 100644 index 00000000000..3ac4a45b943 --- /dev/null +++ b/container-accesslogging/src/test/java/com/yahoo/container/logging/YApacheLogTestCase.java @@ -0,0 +1,300 @@ +// Copyright 2016 Yahoo Inc. 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 org.hamcrest.MatcherAssert; + +import java.io.*; +import java.net.InetSocketAddress; +import java.net.URI; +import java.net.URISyntaxException; +import java.util.Arrays; +import java.util.HashMap; +import java.util.List; +import java.util.Map; + +import static org.hamcrest.CoreMatchers.containsString; +import static org.hamcrest.CoreMatchers.is; +import static org.hamcrest.CoreMatchers.nullValue; +import static org.hamcrest.core.IsNot.not; +import static org.junit.Assert.assertThat; + + +/** + * @author tonytv + */ +public class YApacheLogTestCase extends junit.framework.TestCase { + + private static String ipAddress = "152.200.54.243"; + private static final String EMPTY_REFERRER = ""; + private static final String EMPTY_USERAGENT = ""; + + public void testIt() throws Exception { + AccessLogEntry entry = new AccessLogEntry(); + addCommonEntries(entry); + + entry.setAdSpaceID("676817"); + + AccessLogEntry.AdInfo ad1 = new AccessLogEntry.AdInfo(); + AccessLogEntry.AdInfo ad2 = new AccessLogEntry.AdInfo(); + AccessLogEntry.AdInfo ad3 = new AccessLogEntry.AdInfo(); + + ad1.setAdID("134263"); + ad1.setMatchID("29213.323310.2048738.221486"); + + ad2.setAdID("127077"); + ad2.setMatchID("26036.316814.2030021.40354"); + + ad3.setAdID("127611"); + ad3.setMatchID("26036.330708.2043270.64665"); + + entry.addAdInfo(ad1); + entry.addAdInfo(ad2); + entry.addAdInfo(ad3); + + entry.setUserAgent("Mozilla/4.05 [en] (Win95; I)"); + entry.setWebfactsDigitalSignature("Wk6_cAzC`4IKP\7&)$"); + + entry.setRemoteAddress("17.6.5.4"); + + String expectedOutput = + "98c836f3" + + "36e38385" + + "0001dc90" + + "00002693" + + "/Business/Companies/Financial_Services/Investment_Services/Mutual_Funds/" + + "\u0005gMozilla/4.05 [en] (Win95; I)" + + "\u0005dWk6_cAzC`4IKP\7&)$" + + "\u0005AA17.6.5.4\u0001B12345" + + "\u0005b\u0001676817" + //adinfo + "\u0002134263" + "\u000329213.323310.2048738.221486" + + "\u0002127077" + "\u000326036.316814.2030021.40354" + + "\u0002127611" + "\u000326036.330708.2043270.64665"; + + assertEquals(expectedOutput, new YApacheFormatter(entry).format()); + } + + private void addCommonEntries(AccessLogEntry entry) throws URISyntaxException { + entry.setIpV4Address(ipAddress); + entry.setTimeStamp(920880005L*1000); + entry.setDurationBetweenRequestResponse(122); + entry.setReturnedContentSize(9875); + entry.setURI(new URI("/Business/Companies/Financial_Services/Investment_Services/Mutual_Funds/")); + entry.setRemotePort(12345); + } + + public void test_remote_address_different_from_ip_address() throws Exception { + AccessLogEntry entry = new AccessLogEntry(); + addCommonEntries(entry); + + entry.setRemoteAddress("FE80:0000:0000:0000:0202:B3FF:FE1E:8329"); + + assertEquals("98c836f336e383850001dc9000002693/Business/Companies/Financial_Services/Investment_Services/Mutual_Funds/\u0005AAFE80:0000:0000:0000:0202:B3FF:FE1E:8329\u0001B12345", + new YApacheFormatter(entry).format()); + } + + public void test_remote_address_same_as_ip_address_does_not_cause_double_adding() throws Exception { + AccessLogEntry entry = new AccessLogEntry(); + addCommonEntries(entry); + entry.setRemoteAddress(ipAddress); + + assertThat(new YApacheFormatter(entry).format(), not(containsString(ipAddress))); + } + + public void test_status_code_stored_as_decimal() throws Exception { + AccessLogEntry entry = new AccessLogEntry(); + addCommonEntries(entry); + entry.setStatusCode(404); + + assertThat(new YApacheFormatter(entry).format(), containsString("s404")); + } + + /** + * author someone-else. Please rewrite this. + */ + public void testYApacheAccessLogWithDateNamingScheme() { + AccessLogConfig.Builder builder = new AccessLogConfig.Builder(). + fileHandler(new AccessLogConfig.FileHandler.Builder(). + pattern("yapachetest/testaccess.%Y%m%d%H%M%S"). + symlink("testaccess")); + AccessLogConfig config = new AccessLogConfig(builder); + YApacheAccessLog accessLog = new YApacheAccessLog(config); + try { + final AccessLogEntry entry = newAccessLogEntry("hans"); + accessLog.log(entry); + + // wait for the log writing thread to do all its work, then check it did it right + + // check that symlink appears + int waitTimeMs=0; + while ( ! new File("yapachetest/testaccess").exists()) { + Thread.sleep(2); + waitTimeMs+=2; + if (waitTimeMs>40*1000) + throw new RuntimeException("Waited 40 seconds for the configured symlink to be created, giving up"); + } + // ..and check that the log entry is written + waitTimeMs=0; + while ( ! containsExpectedLine("00000000000000010000271000000008?query=hans","yapachetest/testaccess",0)) { + Thread.sleep(2); + waitTimeMs+=2; + if (waitTimeMs>40*1000) + throw new RuntimeException("Waited 40 seconds for a log file entry to be written, giving up"); + } + } + catch (IOException e) { + throw new RuntimeException("yapache log io exception",e); + } + catch (InterruptedException e) { + throw new RuntimeException("Interruption",e); + } + finally { + accessLog.shutdown(); + deleteDirectory("yapachetest"); + } + } + + public void testThatQueryWithEncodedCharactersIsLoggedInEncodedForm() { + final String query = "%5E%3B%22"; + final AccessLogEntry entry = new AccessLogEntry(); + entry.setURI(newQueryUri(query)); + assertThat(new YApacheFormatter(entry).format(), containsString(query)); + } + + private AccessLogEntry newAccessLogEntry(final String query) { + final AccessLogEntry entry = new AccessLogEntry(); + entry.setIpV4Address("0.0.0.0"); + entry.setUser("user"); + entry.setHttpMethod("GET"); + entry.setURI(newQueryUri(query)); + entry.setHttpVersion("HTTP/1.1"); + entry.setReferer(EMPTY_REFERRER); + entry.setUserAgent(EMPTY_USERAGENT); + entry.setRemoteAddress(new InetSocketAddress(0)); + entry.setTimeStamp(1000); + entry.setDurationBetweenRequestResponse(10); + entry.setReturnedContentSize(8); + entry.setHitCounts(new HitCounts(0, 10, 1234, 0, 10)); + entry.setStatusCode(200); + return entry; + } + + /** + * author someone-else. Please rewrite this. + */ + public void testYApacheAccessLogWithSequenceNamingScheme() throws IOException, InterruptedException { + // try without existing files + assertCorrectSequenceBehavior(1); + + // try with existing files + try { + new File("yapachetest2").mkdir(); + new File("yapachetest2/access.1").createNewFile(); + new File("yapachetest2/access.2").createNewFile(); + assertCorrectSequenceBehavior(3); + } + finally { + deleteDirectory("yapachetest2"); + } + } + + // Prefixes that don't collide with any in the specified log format. + private static final char FIELD_KEY_REQUEST_EXTRA = '@'; + private static final char FIELD_KEY_RESPONSE_EXTRA = '#'; + + + private static List<String> subArrayAsList(final String[] fields, final int fromIndex) { + return Arrays.asList(fields).subList(fromIndex, fields.length); + } + + private static Map<Character, String> makeFieldMap(final Iterable<String> fields) { + final Map<Character, String> fieldMap = new HashMap<>(); + fields.forEach(field -> { + final String existingValue = fieldMap.putIfAbsent(field.charAt(0), field.substring(1)); + MatcherAssert.assertThat("Attempt to insert field " + field + " would overwrite value", existingValue, is(nullValue())); + }); + return fieldMap; + } + + /** + * author someone-else. Please rewrite this. + */ + private void assertCorrectSequenceBehavior(int startN) throws IOException, InterruptedException { + AccessLogConfig.Builder builder = new AccessLogConfig.Builder(). + fileHandler(new AccessLogConfig.FileHandler.Builder(). + pattern("yapachetest2/access"). + rotateScheme(AccessLogConfig.FileHandler.RotateScheme.Enum.SEQUENCE)); + + AccessLogConfig config = new AccessLogConfig(builder); + YApacheAccessLog accessLog = new YApacheAccessLog(config); + try { + // log and rotate trice + accessLog.log(newAccessLogEntry("query1")); + accessLog.rotateNow(); + accessLog.log(newAccessLogEntry("query2")); + accessLog.rotateNow(); + accessLog.log(newAccessLogEntry("query3.1")); + accessLog.log(newAccessLogEntry("query3.2")); + accessLog.rotateNow(); + accessLog.log(newAccessLogEntry("query4")); + + // wait for the last rotation, which should cause us to have an "access" file containing query4 + int waitTimeMs=0; + while ( ! containsExpectedLine("00000000000000010000271000000008?query=query4","yapachetest2/access",0)) { + Thread.sleep(2); + waitTimeMs+=2; + if (waitTimeMs>40*1000) + throw new RuntimeException("Waited 40 seconds for the right log file entry to be written, giving up"); + } + + // Should now have 3 rotated away files + assertTrue(containsExpectedLine("00000000000000010000271000000008?query=query1","yapachetest2/access." + (startN+0),0)); + assertTrue(containsExpectedLine("00000000000000010000271000000008?query=query2","yapachetest2/access." + (startN+1),0)); + assertTrue(containsExpectedLine("00000000000000010000271000000008?query=query3.1","yapachetest2/access." + (startN+2),0)); + assertTrue(containsExpectedLine("00000000000000010000271000000008?query=query3.2","yapachetest2/access." + (startN+2),1)); + } + finally { + accessLog.shutdown(); + deleteDirectory("yapachetest2"); + } + } + + private void deleteDirectory(String name) { + File dir=new File(name); + if (! dir.exists()) return; + for (File f : dir.listFiles()) + f.delete(); + dir.delete(); + } + + /** + * Returns whether this file contains this line as the first one. + * If line is null: Checks that the file is empty. + * + * author someone-else. Please rewrite this. + */ + private boolean containsExpectedLine(String line,String file,int lineNumber) throws IOException { + BufferedReader reader=null; + try { + reader=new BufferedReader(new FileReader(file)); + if (line==null) return reader.readLine()==null; + while (lineNumber-- > 0) { + String l = reader.readLine(); + } + String l = reader.readLine(); + return l != null && l.startsWith(line); + } + catch (FileNotFoundException e) { + return false; + } + finally { + if (reader!=null) + reader.close(); + } + } + + private static URI newQueryUri(final String query) { + return URI.create("http://localhost?query=" + query); + } + +} diff --git a/container-accesslogging/src/test/java/com/yahoo/container/logging/test/LogFileHandlerTestCase.java b/container-accesslogging/src/test/java/com/yahoo/container/logging/test/LogFileHandlerTestCase.java new file mode 100644 index 00000000000..99f1132b7bb --- /dev/null +++ b/container-accesslogging/src/test/java/com/yahoo/container/logging/test/LogFileHandlerTestCase.java @@ -0,0 +1,224 @@ +// Copyright 2016 Yahoo Inc. 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.LogFileHandler; + +import java.io.File; +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; + +/** + * @author <a href="mailto:travisb@yahoo-inc.com">Bob Travis</a> + */ +// TODO: Make these tests wait until the right things happen rather than waiting for a predetermined time +// These tests take too long, and are not cleaning up properly. See how this should be done in YApacheLogTestCase +public class LogFileHandlerTestCase extends junit.framework.TestCase { + + public LogFileHandlerTestCase(String name) { + super(name); + } + + /** + * The scenario + */ + public void testIt() { + LogFileHandler h = new LogFileHandler(); + h.setFilePattern("./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; + assertEquals (tomorrowMillis, h.getNextRotationTime(now)); + long[] rTimes = {1000, 2000, 10000}; + h.setRotationTimes(rTimes); + assertEquals (tomorrowMillis+1000, h.getNextRotationTime(tomorrowMillis)); + assertEquals (tomorrowMillis+10000, h.getNextRotationTime(tomorrowMillis+3000)); + boolean okToWrite = false; // don't want regular unit tests to create tiles.... + if (okToWrite) { + 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(); + } + } + + private boolean delete(String fileOrDir) { + File file = new File(fileOrDir); + return file.delete(); + } + + // Feeble attempt to get rid of test dirs and files somewhat more reliably in these poorly written tests + private void delete2(String fileOrDir) { + File file = new File(fileOrDir); + file.deleteOnExit(); + } + + public void testDeleteFileFirst() { + String logFilePattern = "./testLogFileG.txt"; + + //delete log file + delete(logFilePattern); + + //create logfilehandler + LogFileHandler h = new LogFileHandler(); + h.setFilePattern(logFilePattern); + h.setFormatter(new SimpleFormatter()); + h.setRotationTimes("0 5 ..."); + + //write log + LogRecord lr = new LogRecord(Level.INFO, "testDeleteFileFirst1"); + h.publish(lr); + h.flush(); + + //delete log file + delete2(logFilePattern); + } + + public void testDeleteDirFirst() { + //delete log file and dir + delete("./testlogsG/foo/bar/testlog"); + delete("./testlogsG/foo/bar"); + delete("./testlogsG/foo"); + delete("./testlogsG"); + + //create logfilehandler + LogFileHandler h = new LogFileHandler(); + h.setFilePattern("./testlogsG/foo/bar/testlog"); + h.setFormatter(new SimpleFormatter()); + h.setRotationTimes("0 5 ..."); + + //write log + LogRecord lr = new LogRecord(Level.INFO, "testDeleteDirFirst1"); + h.publish(lr); + h.flush(); + + //delete log file and dir + delete2("./testlogsG/foo/bar/testlog"); + delete2("./testlogsG/foo/bar"); + delete2("./testlogsG/foo"); + delete2("./testlogsG"); + } + + public void testDeleteFileDuringLogging() { + String logFilePattern = "./testLogFileG.txt"; + + //create logfilehandler + LogFileHandler h = new LogFileHandler(); + h.setFilePattern(logFilePattern); + 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 + delete(logFilePattern); + + //write log again + lr = new LogRecord(Level.INFO, "testDeleteFileDuringLogging2"); + h.publish(lr); + h.flush(); + + //delete log file + delete2(logFilePattern); + } + + public void testDeleteDirDuringLogging() { + //create logfilehandler + LogFileHandler h = new LogFileHandler(); + h.setFilePattern("./testlogsG/foo/bar/testlog"); + h.setFormatter(new SimpleFormatter()); + h.setRotationTimes("0 5 ..."); + + //write log + LogRecord lr = new LogRecord(Level.INFO, "testDeleteDirDuringLogging1"); + h.publish(lr); + h.flush(); + + //delete log file and dir + delete("./testlogsG/foo/bar/testlog"); + delete("./testlogsG/foo/bar"); + delete("./testlogsG/foo"); + delete("./testlogsG"); + + //write log + lr = new LogRecord(Level.INFO, "testDeleteDirDuringLogging2"); + h.publish(lr); + h.flush(); + + //delete log file and dir + delete2("./testlogsG/foo/bar/testlog"); + delete2("./testlogsG/foo/bar"); + delete2("./testlogsG/foo"); + delete2("./testlogsG"); + } + + public void testSymlink() { + LogFileHandler h = new LogFileHandler(); + h.setFilePattern("./testlogforsymlinkchecking/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"); + } + } ); + h.setSymlinkName("symlink"); + LogRecord lr = new LogRecord(Level.INFO, "test"); + h.publish(lr); + String f1 = h.getFileName(); + try { + while (f1 == null) { + Thread.sleep(1); + f1 = h.getFileName(); + } + h.rotateNow(); + Thread.sleep(1); + String f2 = h.getFileName(); + while (f1.equals(f2)) { + Thread.sleep(1); + f2 = h.getFileName(); + } + lr = new LogRecord(Level.INFO, "string which is way longer than the word test"); + h.publish(lr); + Thread.sleep(1000); + File f = new File(f1); + long first = f.length(); + f = new File(f2); + long second = f.length(); + final long secondLength = 72; + for (int n = 0; n < 20 && second != secondLength; ++n) { + Thread.sleep(1000); + second = f.length(); + } + f = new File("./testlogforsymlinkchecking", "symlink"); + long link = f.length(); + assertEquals(secondLength, link); + assertEquals(31, first); + assertEquals(secondLength, second); + delete2(f2); + } catch (InterruptedException e) { + // just let the test pass + } + delete2(f1); + delete2("./testlogforsymlinkchecking/symlink"); + delete2("./testlogforsymlinkchecking"); + } + +} 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 new file mode 100644 index 00000000000..f2051a9f9e0 --- /dev/null +++ b/container-accesslogging/src/test/java/com/yahoo/container/logging/test/LogFormatterTestCase.java @@ -0,0 +1,27 @@ +// Copyright 2016 Yahoo Inc. 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; + +/** + * @author <a href="mailto:travisb@yahoo-inc.com">Bob Travis</a> + */ +public class LogFormatterTestCase extends junit.framework.TestCase { + + public LogFormatterTestCase(String name) { + super(name); + } + + 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); + } + +} |