diff options
Diffstat (limited to 'jdisc_http_service/src/main/java/com')
8 files changed, 116 insertions, 134 deletions
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 index 08be5f2613e..4c156e2705f 100644 --- 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 @@ -11,14 +11,14 @@ import java.util.logging.LogRecord; */ class AccessLogHandler { - private final LogFileHandler logFileHandler; + private final LogFileHandler<RequestLogEntry> logFileHandler; - AccessLogHandler(AccessLogConfig.FileHandler config) { - logFileHandler = new LogFileHandler(toCompression(config), config.pattern(), config.rotation(), config.symlink()); + AccessLogHandler(AccessLogConfig.FileHandler config, LogWriter<RequestLogEntry> logWriter) { + logFileHandler = new LogFileHandler<>(toCompression(config), config.pattern(), config.rotation(), config.symlink(), logWriter); } - public void log(String message) { - logFileHandler.publish(new LogRecord(Level.INFO, message)); + public void log(RequestLogEntry entry) { + logFileHandler.publish(entry); } private LogFileHandler.Compression toCompression(AccessLogConfig.FileHandler config) { @@ -32,12 +32,6 @@ class AccessLogHandler { void shutdown() { logFileHandler.close(); - - if (logFileHandler!=null) - logFileHandler.shutdown(); - } - - void rotateNow() { - logFileHandler.rotateNow(); + logFileHandler.shutdown(); } } diff --git a/jdisc_http_service/src/main/java/com/yahoo/container/logging/ConnectionLogHandler.java b/jdisc_http_service/src/main/java/com/yahoo/container/logging/ConnectionLogHandler.java index 82a84200f10..2a36e251d24 100644 --- a/jdisc_http_service/src/main/java/com/yahoo/container/logging/ConnectionLogHandler.java +++ b/jdisc_http_service/src/main/java/com/yahoo/container/logging/ConnectionLogHandler.java @@ -4,24 +4,24 @@ package com.yahoo.container.logging; import java.util.logging.Level; import java.util.logging.LogRecord; -import java.util.logging.Logger; /** * @author mortent */ class ConnectionLogHandler { - private final LogFileHandler logFileHandler; + private final LogFileHandler<ConnectionLogEntry> logFileHandler; - public ConnectionLogHandler(String clusterName) { - logFileHandler = new LogFileHandler( + public ConnectionLogHandler(String clusterName, LogWriter<ConnectionLogEntry> logWriter) { + logFileHandler = new LogFileHandler<>( LogFileHandler.Compression.ZSTD, String.format("logs/vespa/qrs/ConnectionLog.%s.%s", clusterName, "%Y%m%d%H%M%S"), "0 60 ...", - String.format("ConnectionLog.%s", clusterName)); + String.format("ConnectionLog.%s", clusterName), + logWriter); } - public void log(String message) { - logFileHandler.publish(new LogRecord(Level.INFO, message)); + public void log(ConnectionLogEntry entry) { + logFileHandler.publish(entry); } public void shutdown() { diff --git a/jdisc_http_service/src/main/java/com/yahoo/container/logging/FileConnectionLog.java b/jdisc_http_service/src/main/java/com/yahoo/container/logging/FileConnectionLog.java index 0b9e2e4a778..62e53a5a514 100644 --- a/jdisc_http_service/src/main/java/com/yahoo/container/logging/FileConnectionLog.java +++ b/jdisc_http_service/src/main/java/com/yahoo/container/logging/FileConnectionLog.java @@ -5,33 +5,38 @@ package com.yahoo.container.logging; import com.google.inject.Inject; import com.yahoo.component.AbstractComponent; +import java.io.IOException; +import java.io.OutputStream; +import java.nio.charset.StandardCharsets; import java.util.logging.Level; import java.util.logging.Logger; /** * @author mortent */ -public class FileConnectionLog extends AbstractComponent implements ConnectionLog { +public class FileConnectionLog extends AbstractComponent implements ConnectionLog, LogWriter<ConnectionLogEntry> { private static final Logger logger = Logger.getLogger(FileConnectionLog.class.getName()); private final ConnectionLogHandler logHandler; @Inject public FileConnectionLog(ConnectionLogConfig config) { - logHandler = new ConnectionLogHandler(config.cluster()); + logHandler = new ConnectionLogHandler(config.cluster(), this); } @Override public void log(ConnectionLogEntry connectionLogEntry) { - try { - logHandler.log(connectionLogEntry.toJson()+ '\n'); - } catch (Exception e) { - logger.log(Level.WARNING, "Unable to write connection log entry for connection id " + connectionLogEntry.id(), e); - } + logHandler.log(connectionLogEntry); } @Override public void deconstruct() { logHandler.shutdown(); } + + @Override + // TODO serialize directly to outputstream + public void write(ConnectionLogEntry entry, OutputStream outputStream) throws IOException { + outputStream.write(entry.toJson().getBytes(StandardCharsets.UTF_8)); + } }
\ No newline at end of file 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 index 6fc4e886ec5..2cea7f7dd04 100644 --- 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 @@ -12,25 +12,18 @@ import com.yahoo.container.core.AccessLogConfig; public final class JSONAccessLog implements RequestLogHandler { private final AccessLogHandler logHandler; - private final JSONFormatter formatter; public JSONAccessLog(AccessLogConfig config) { - logHandler = new AccessLogHandler(config.fileHandler()); - formatter = new JSONFormatter(); + logHandler = new AccessLogHandler(config.fileHandler(), new JSONFormatter()); } @Override public void log(RequestLogEntry entry) { - logHandler.log(formatter.format(entry) + '\n'); + logHandler.log(entry); } // 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 index e813b1bf4e1..c6d177684ac 100644 --- 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 @@ -7,8 +7,8 @@ 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.io.OutputStream; import java.security.Principal; import java.util.Collection; import java.util.Objects; @@ -20,7 +20,7 @@ import java.util.logging.Logger; * * @author frodelu */ -public class JSONFormatter { +public class JSONFormatter implements LogWriter<RequestLogEntry> { private static final String COVERAGE = "coverage"; private static final String COVERAGE_COVERAGE = "coverage"; private static final String COVERAGE_DOCUMENTS = "documents"; @@ -38,15 +38,9 @@ public class JSONFormatter { generatorFactory = new JsonFactory(new ObjectMapper()); } - /** - * The main method for formatting the associated {@link RequestLogEntry} as a Vespa JSON access log string - * - * @return The Vespa JSON access log string without trailing newline - */ - public String format(RequestLogEntry entry) { - ByteArrayOutputStream logLine = new ByteArrayOutputStream(); - try { - JsonGenerator generator = generatorFactory.createGenerator(logLine, JsonEncoding.UTF8); + @Override + public void write(RequestLogEntry entry, OutputStream outputStream) throws IOException { + try (JsonGenerator generator = createJsonGenerator(outputStream)){ generator.writeStartObject(); String peerAddress = entry.peerAddress().get(); generator.writeStringField("ip", peerAddress); @@ -152,15 +146,16 @@ public class JSONFormatter { } generator.writeEndObject(); - generator.close(); - } catch (IOException e) { logger.log(Level.WARNING, "Unable to generate JSON access log entry: " + e.getMessage(), e); } - - return logLine.toString(); } + private JsonGenerator createJsonGenerator(OutputStream outputStream) throws IOException { + return generatorFactory.createGenerator(outputStream, JsonEncoding.UTF8) + .configure(JsonGenerator.Feature.AUTO_CLOSE_TARGET, false) + .configure(JsonGenerator.Feature.FLUSH_PASSED_TO_STREAM, false); + } private boolean remoteAddressDiffers(String ipV4Address, String remoteAddress) { return remoteAddress != null && !Objects.equals(ipV4Address, remoteAddress); 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 index 58a324b7f26..b764f813c41 100644 --- 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 @@ -13,11 +13,6 @@ import java.io.FileInputStream; import java.io.FileOutputStream; import java.io.IOException; import java.io.InputStream; -import java.io.OutputStream; -import java.io.OutputStreamWriter; -import java.io.UnsupportedEncodingException; -import java.io.Writer; -import java.nio.charset.StandardCharsets; import java.nio.file.Files; import java.nio.file.Path; import java.nio.file.Paths; @@ -27,12 +22,9 @@ import java.util.concurrent.ArrayBlockingQueue; import java.util.concurrent.ExecutorService; import java.util.concurrent.Executors; import java.util.concurrent.TimeUnit; -import java.util.logging.ErrorManager; -import java.util.logging.Formatter; +import java.util.concurrent.atomic.AtomicBoolean; 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; /** @@ -41,7 +33,7 @@ import java.util.zip.GZIPOutputStream; * @author Bob Travis * @author bjorncs */ -class LogFileHandler { +class LogFileHandler <LOGTYPE> { enum Compression { NONE, GZIP, ZSTD } @@ -51,23 +43,23 @@ class LogFileHandler { private final long[] rotationTimes; private final String filePattern; // default to current directory, ms time stamp private final String symlinkName; - private final ArrayBlockingQueue<LogRecord> logQueue = new ArrayBlockingQueue<>(100000); - private final LogRecord rotateCmd = new LogRecord(Level.SEVERE, "rotateNow"); + private final ArrayBlockingQueue<LOGTYPE> logQueue = new ArrayBlockingQueue<>(100000); + private final AtomicBoolean rotate = new AtomicBoolean(false); private final ExecutorService executor = Executors.newCachedThreadPool(ThreadFactoryFactory.getDaemonThreadFactory("logfilehandler.compression")); private final NativeIO nativeIO = new NativeIO(); - private final LogThread logThread; + private final LogThread<LOGTYPE> logThread; private volatile FileOutputStream currentOutputStream = null; private volatile long nextRotationTime = 0; private volatile String fileName; private volatile long lastDropPosition = 0; - private volatile Writer writer; + private final LogWriter<LOGTYPE> logWriter; - static private class LogThread extends Thread { - LogFileHandler logFileHandler; + static private class LogThread<LOGTYPE> extends Thread { + final LogFileHandler<LOGTYPE> logFileHandler; long lastFlush = 0; - LogThread(LogFileHandler logFile) { + LogThread(LogFileHandler<LOGTYPE> logFile) { super("Logger"); setDaemon(true); logFileHandler = logFile; @@ -86,14 +78,14 @@ class LogFileHandler { private void storeLogRecords() throws InterruptedException { while (!isInterrupted()) { - LogRecord r = logFileHandler.logQueue.poll(100, TimeUnit.MILLISECONDS); + LOGTYPE r = logFileHandler.logQueue.poll(100, TimeUnit.MILLISECONDS); + if(logFileHandler.rotate.get()) { + logFileHandler.internalRotateNow(); + lastFlush = System.nanoTime(); + logFileHandler.rotate.set(false); + } if (r != null) { - if (r == logFileHandler.rotateCmd) { - logFileHandler.internalRotateNow(); - lastFlush = System.nanoTime(); - } else { - logFileHandler.internalPublish(r); - } + logFileHandler.internalPublish(r); flushIfOld(3, TimeUnit.SECONDS); } else { flushIfOld(100, TimeUnit.MILLISECONDS); @@ -110,20 +102,21 @@ class LogFileHandler { } } - LogFileHandler(Compression compression, String filePattern, String rotationTimes, String symlinkName) { - this(compression, filePattern, calcTimesMinutes(rotationTimes), symlinkName); + LogFileHandler(Compression compression, String filePattern, String rotationTimes, String symlinkName, LogWriter<LOGTYPE> logWriter) { + this(compression, filePattern, calcTimesMinutes(rotationTimes), symlinkName, logWriter); } LogFileHandler( Compression compression, String filePattern, long[] rotationTimes, - String symlinkName) { + String symlinkName, LogWriter<LOGTYPE> logWriter) { this.compression = compression; this.filePattern = filePattern; this.rotationTimes = rotationTimes; this.symlinkName = (symlinkName != null && !symlinkName.isBlank()) ? symlinkName : null; - this.logThread = new LogThread(this); + this.logWriter = logWriter; + this.logThread = new LogThread<>(this); this.logThread.start(); } @@ -132,7 +125,7 @@ class LogFileHandler { * * @param r logrecord to publish */ - public void publish(LogRecord r) { + public void publish(LOGTYPE r) { try { logQueue.put(r); } catch (InterruptedException e) { @@ -140,19 +133,17 @@ class LogFileHandler { } public synchronized void flush() { - if(writer != null) { - try { - writer.flush(); - } catch (IOException e) { - logger.warning("Failed flushing file writer: " + Exceptions.toMessageString(e)); - } - } try { - if (currentOutputStream != null && compression == Compression.GZIP) { - long newPos = currentOutputStream.getChannel().position(); - if (newPos > lastDropPosition + 102400) { - nativeIO.dropPartialFileFromCache(currentOutputStream.getFD(), lastDropPosition, newPos, true); - lastDropPosition = newPos; + FileOutputStream currentOut = this.currentOutputStream; + if (currentOut != null) { + if (compression == Compression.GZIP) { + long newPos = currentOut.getChannel().position(); + if (newPos > lastDropPosition + 102400) { + nativeIO.dropPartialFileFromCache(currentOut.getFD(), lastDropPosition, newPos, true); + lastDropPosition = newPos; + } + } else { + currentOut.flush(); } } } catch (IOException e) { @@ -160,30 +151,17 @@ class LogFileHandler { } } - private synchronized void setOutputStream(OutputStream out) { - if (out == null) { - throw new NullPointerException(); - } - flushAndClose(); - writer = new OutputStreamWriter(out, StandardCharsets.UTF_8); - } - private synchronized void flushAndClose() throws SecurityException { - if (writer != null) { - try { - writer.flush(); - writer.close(); - } catch (Exception ex) { - logger.log(Level.SEVERE, "Failed to close writer", ex); - } - writer = null; - } - } - public void close() { - flushAndClose(); + try { + flush(); + FileOutputStream currentOut = this.currentOutputStream; + if (currentOut != null) currentOut.close(); + } catch (Exception e) { + logger.log(Level.WARNING, "Got error while closing log file", e); + } } - private void internalPublish(LogRecord r) { + private void internalPublish(LOGTYPE r) { // first check to see if new file needed. // if so, use this.internalRotateNow() to do it @@ -195,7 +173,7 @@ class LogFileHandler { internalRotateNow(); } try { - writer.write(r.getMessage()); + logWriter.write(r, currentOutputStream); } catch (IOException e) { logger.warning("Failed writing log record: " + Exceptions.toMessageString(e)); } @@ -251,7 +229,7 @@ class LogFileHandler { * Force file rotation now, independent of schedule. */ void rotateNow () { - publish(rotateCmd); + rotate.set(true); } // Throw InterruptedException upwards rather than relying on isInterrupted to stop the thread as @@ -264,12 +242,10 @@ class LogFileHandler { long now = System.currentTimeMillis(); fileName = LogFormatter.insertDate(filePattern, now); flush(); - flushAndClose(); try { checkAndCreateDir(fileName); FileOutputStream os = new FileOutputStream(fileName, true); // append mode, for safety - setOutputStream(os); currentOutputStream = os; lastDropPosition = 0; LogFileDb.nowLoggingTo(fileName); diff --git a/jdisc_http_service/src/main/java/com/yahoo/container/logging/LogWriter.java b/jdisc_http_service/src/main/java/com/yahoo/container/logging/LogWriter.java new file mode 100644 index 00000000000..15a983cfb43 --- /dev/null +++ b/jdisc_http_service/src/main/java/com/yahoo/container/logging/LogWriter.java @@ -0,0 +1,10 @@ +// Copyright Verizon Media. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. + +package com.yahoo.container.logging; + +import java.io.IOException; +import java.io.OutputStream; + +interface LogWriter <LOGTYPE> { + void write(LOGTYPE record, OutputStream outputStream) throws IOException; +} diff --git a/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 index 347500a8c07..b74e69ce172 100644 --- 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 @@ -3,6 +3,9 @@ package com.yahoo.container.logging; import com.yahoo.container.core.AccessLogConfig; +import java.io.IOException; +import java.io.OutputStream; +import java.nio.charset.StandardCharsets; import java.text.SimpleDateFormat; import java.util.Date; import java.util.TimeZone; @@ -12,14 +15,14 @@ import java.util.logging.Level; * @author Bjorn Borud * @author Oyvind Bakksjo */ -public final class VespaAccessLog implements RequestLogHandler { +public final class VespaAccessLog implements RequestLogHandler, LogWriter<RequestLogEntry> { private static final ThreadLocal<SimpleDateFormat> dateFormat = ThreadLocal.withInitial(VespaAccessLog::createDateFormat); private final AccessLogHandler logHandler; public VespaAccessLog(AccessLogConfig config) { - logHandler = new AccessLogHandler(config.fileHandler()); + logHandler = new AccessLogHandler(config.fileHandler(), this); } private static SimpleDateFormat createDateFormat() { @@ -40,7 +43,7 @@ public final class VespaAccessLog implements RequestLogHandler { return (user == null) ? "-" : user; } - private void writeLog(String ipAddr, String user, String request, String referer, String agent, + private String toLogline(String ipAddr, String user, String request, String referer, String agent, long durationMillis, long byteCount, HitCounts hitcounts, int returnCode) { long ms = Math.max(0L, durationMillis); @@ -69,7 +72,7 @@ public final class VespaAccessLog implements RequestLogHandler { .append(" 0.0 ") .append((hitcounts == null) ? 0 : hitcounts.getSummaryCount()) .append('\n'); - logHandler.log(sb.toString()); + return sb.toString(); } private void decimalsOfSecondsFromMilliseconds(long ms, StringBuilder sb) { @@ -93,19 +96,25 @@ public final class VespaAccessLog implements RequestLogHandler { @Override public void log(RequestLogEntry entry) { - writeLog( - entry.peerAddress().get(), - null, - getRequest( - entry.httpMethod().orElse(null), - entry.rawPath().orElse(null), - entry.rawQuery().orElse(null), - entry.httpVersion().orElse(null)), - entry.referer().orElse(null), - entry.userAgent().orElse(null), - entry.duration().get().toMillis(), - entry.contentSize().orElse(0L), - entry.hitCounts().orElse(null), - entry.statusCode().orElse(0)); + logHandler.log(entry); + } + + @Override + public void write(RequestLogEntry entry, OutputStream outputStream) throws IOException { + outputStream.write( + toLogline( + entry.peerAddress().get(), + null, + getRequest( + entry.httpMethod().orElse(null), + entry.rawPath().orElse(null), + entry.rawQuery().orElse(null), + entry.httpVersion().orElse(null)), + entry.referer().orElse(null), + entry.userAgent().orElse(null), + entry.duration().get().toMillis(), + entry.contentSize().orElse(0L), + entry.hitCounts().orElse(null), + entry.statusCode().orElse(0)).getBytes(StandardCharsets.UTF_8)); } } |