Merge remote-tracking branch 'origin/jetty-10.0.x' into jetty-11.0.x

This commit is contained in:
Lachlan Roberts 2020-08-21 10:38:30 +10:00
commit 311bcf42a5
7 changed files with 228 additions and 47 deletions

View File

@ -31,7 +31,6 @@
<groupId>org.mongodb</groupId>
<artifactId>mongo-java-driver</artifactId>
<version>2.13.2</version>
<type>jar</type>
<scope>compile</scope>
</dependency>
<dependency>

View File

@ -30,6 +30,7 @@ import java.util.concurrent.TimeUnit;
import java.util.function.Supplier;
import java.util.regex.Matcher;
import java.util.regex.Pattern;
import java.util.stream.Collectors;
import jakarta.servlet.http.Cookie;
import jakarta.servlet.http.HttpServletRequest;
@ -274,18 +275,15 @@ public class CustomRequestLog extends ContainerLifeCycle implements RequestLog
protected static final Logger LOG = LoggerFactory.getLogger(CustomRequestLog.class);
public static final String DEFAULT_DATE_FORMAT = "dd/MMM/yyyy:HH:mm:ss ZZZ";
public static final String NCSA_FORMAT = "%{client}a - %u %t \"%r\" %s %O";
public static final String EXTENDED_NCSA_FORMAT = NCSA_FORMAT + " \"%{Referer}i\" \"%{User-Agent}i\"";
private static final ThreadLocal<StringBuilder> _buffers = ThreadLocal.withInitial(() -> new StringBuilder(256));
private static ThreadLocal<StringBuilder> _buffers = ThreadLocal.withInitial(() -> new StringBuilder(256));
private String[] _ignorePaths;
private transient PathMappings<String> _ignorePathMap;
private RequestLog.Writer _requestLogWriter;
private final RequestLog.Writer _requestLogWriter;
private final MethodHandle _logHandle;
private final String _formatString;
private transient PathMappings<String> _ignorePathMap;
private String[] _ignorePaths;
public CustomRequestLog()
{
@ -450,8 +448,10 @@ public class CustomRequestLog extends ContainerLifeCycle implements RequestLog
{
if (t.isLiteralString())
logHandle = updateLogHandle(logHandle, append, t.literal);
else
else if (t.isPercentCode())
logHandle = updateLogHandle(logHandle, append, lookup, t.code, t.arg, t.modifiers, t.negated);
else
throw new IllegalStateException("bad token " + t);
}
return logHandle;
@ -484,6 +484,7 @@ public class CustomRequestLog extends ContainerLifeCycle implements RequestLog
String arg = m.group("ARG");
String modifierString = m.group("MOD");
List<Integer> modifiers = null;
boolean negated = false;
if (modifierString != null)
{
@ -492,9 +493,14 @@ public class CustomRequestLog extends ContainerLifeCycle implements RequestLog
modifierString = modifierString.substring(1);
negated = true;
}
modifiers = new QuotedCSV(modifierString)
.getValues()
.stream()
.map(Integer::parseInt)
.collect(Collectors.toList());
}
List<String> modifiers = new QuotedCSV(modifierString).getValues();
tokens.add(new Token(code, arg, modifiers, negated));
}
else if (m.group("LITERAL") != null)
@ -522,18 +528,17 @@ public class CustomRequestLog extends ContainerLifeCycle implements RequestLog
{
public final String code;
public final String arg;
public final List<String> modifiers;
public final List<Integer> modifiers;
public final boolean negated;
public final String literal;
public Token(String code, String arg, List<String> modifiers, boolean negated)
public Token(String code, String arg, List<Integer> modifiers, boolean negated)
{
this.code = code;
this.arg = arg;
this.modifiers = modifiers;
this.negated = negated;
this.literal = null;
}
@ -543,7 +548,6 @@ public class CustomRequestLog extends ContainerLifeCycle implements RequestLog
this.arg = null;
this.modifiers = null;
this.negated = false;
this.literal = literal;
}
@ -558,18 +562,13 @@ public class CustomRequestLog extends ContainerLifeCycle implements RequestLog
}
}
//TODO use integer comparisons instead of strings
private static boolean modify(List<String> modifiers, Boolean negated, StringBuilder b, Request request, Response response)
@SuppressWarnings("unused")
private static boolean modify(List<Integer> modifiers, Boolean negated, StringBuilder b, Request request, Response response)
{
String responseCode = Integer.toString(response.getStatus());
if (negated)
{
return (!modifiers.contains(responseCode));
}
return !modifiers.contains(response.getStatus());
else
{
return (modifiers.contains(responseCode));
}
return modifiers.contains(response.getStatus());
}
private MethodHandle updateLogHandle(MethodHandle logHandle, MethodHandle append, String literal)
@ -577,7 +576,7 @@ public class CustomRequestLog extends ContainerLifeCycle implements RequestLog
return foldArguments(logHandle, dropArguments(dropArguments(append.bindTo(literal), 1, Request.class), 2, Response.class));
}
private MethodHandle updateLogHandle(MethodHandle logHandle, MethodHandle append, MethodHandles.Lookup lookup, String code, String arg, List<String> modifiers, boolean negated) throws NoSuchMethodException, IllegalAccessException
private MethodHandle updateLogHandle(MethodHandle logHandle, MethodHandle append, MethodHandles.Lookup lookup, String code, String arg, List<Integer> modifiers, boolean negated) throws NoSuchMethodException, IllegalAccessException
{
MethodType logType = methodType(void.class, StringBuilder.class, Request.class, Response.class);
MethodType logTypeArg = methodType(void.class, String.class, StringBuilder.class, Request.class, Response.class);
@ -913,12 +912,12 @@ public class CustomRequestLog extends ContainerLifeCycle implements RequestLog
if (modifiers != null && !modifiers.isEmpty())
{
MethodHandle modifierTest = lookup.findStatic(CustomRequestLog.class, "modify", methodType(Boolean.TYPE, List.class, Boolean.class, StringBuilder.class, Request.class, Response.class));
MethodHandle dash = updateLogHandle(logHandle, append, "-");
MethodHandle log = foldArguments(logHandle, specificHandle);
modifierTest = modifierTest.bindTo(modifiers).bindTo(negated);
MethodHandle modifierTest = lookup.findStatic(CustomRequestLog.class, "modify",
methodType(Boolean.TYPE, List.class, Boolean.class, StringBuilder.class, Request.class, Response.class));
modifierTest = modifierTest.bindTo(modifiers).bindTo(negated);
return MethodHandles.guardWithTest(modifierTest, log, dash);
}
@ -926,57 +925,67 @@ public class CustomRequestLog extends ContainerLifeCycle implements RequestLog
}
//-----------------------------------------------------------------------------------//
@SuppressWarnings("unused")
private static void logNothing(StringBuilder b, Request request, Response response)
{
}
@SuppressWarnings("unused")
private static void logServerHost(StringBuilder b, Request request, Response response)
{
append(b, request.getServerName());
}
@SuppressWarnings("unused")
private static void logClientHost(StringBuilder b, Request request, Response response)
{
append(b, request.getRemoteHost());
}
@SuppressWarnings("unused")
private static void logLocalHost(StringBuilder b, Request request, Response response)
{
append(b, request.getHttpChannel().getEndPoint().getLocalAddress().getAddress().getHostAddress());
}
@SuppressWarnings("unused")
private static void logRemoteHost(StringBuilder b, Request request, Response response)
{
append(b, request.getHttpChannel().getEndPoint().getRemoteAddress().getAddress().getHostAddress());
}
@SuppressWarnings("unused")
private static void logServerPort(StringBuilder b, Request request, Response response)
{
b.append(request.getServerPort());
}
@SuppressWarnings("unused")
private static void logClientPort(StringBuilder b, Request request, Response response)
{
b.append(request.getRemotePort());
}
@SuppressWarnings("unused")
private static void logLocalPort(StringBuilder b, Request request, Response response)
{
b.append(request.getHttpChannel().getEndPoint().getLocalAddress().getPort());
}
@SuppressWarnings("unused")
private static void logRemotePort(StringBuilder b, Request request, Response response)
{
b.append(request.getHttpChannel().getEndPoint().getRemoteAddress().getPort());
}
@SuppressWarnings("unused")
private static void logResponseSize(StringBuilder b, Request request, Response response)
{
long written = response.getHttpChannel().getBytesWritten();
b.append(written);
}
@SuppressWarnings("unused")
private static void logResponseSizeCLF(StringBuilder b, Request request, Response response)
{
long written = response.getHttpChannel().getBytesWritten();
@ -986,11 +995,13 @@ public class CustomRequestLog extends ContainerLifeCycle implements RequestLog
b.append(written);
}
@SuppressWarnings("unused")
private static void logBytesSent(StringBuilder b, Request request, Response response)
{
b.append(response.getHttpChannel().getBytesWritten());
}
@SuppressWarnings("unused")
private static void logBytesSentCLF(StringBuilder b, Request request, Response response)
{
long sent = response.getHttpChannel().getBytesWritten();
@ -1000,38 +1011,39 @@ public class CustomRequestLog extends ContainerLifeCycle implements RequestLog
b.append(sent);
}
@SuppressWarnings("unused")
private static void logBytesReceived(StringBuilder b, Request request, Response response)
{
//todo this be content received rather than consumed
b.append(request.getHttpInput().getContentConsumed());
b.append(request.getHttpInput().getContentReceived());
}
@SuppressWarnings("unused")
private static void logBytesReceivedCLF(StringBuilder b, Request request, Response response)
{
//todo this be content received rather than consumed
long received = request.getHttpInput().getContentConsumed();
long received = request.getHttpInput().getContentReceived();
if (received == 0)
b.append('-');
else
b.append(received);
}
@SuppressWarnings("unused")
private static void logBytesTransferred(StringBuilder b, Request request, Response response)
{
//todo this be content received rather than consumed
b.append(request.getHttpInput().getContentConsumed() + response.getHttpOutput().getWritten());
b.append(request.getHttpInput().getContentReceived() + response.getHttpOutput().getWritten());
}
@SuppressWarnings("unused")
private static void logBytesTransferredCLF(StringBuilder b, Request request, Response response)
{
//todo this be content received rather than consumed
long transferred = request.getHttpInput().getContentConsumed() + response.getHttpOutput().getWritten();
long transferred = request.getHttpInput().getContentReceived() + response.getHttpOutput().getWritten();
if (transferred == 0)
b.append('-');
else
b.append(transferred);
}
@SuppressWarnings("unused")
private static void logRequestCookie(String arg, StringBuilder b, Request request, Response response)
{
Cookie[] cookies = request.getCookies();
@ -1050,6 +1062,7 @@ public class CustomRequestLog extends ContainerLifeCycle implements RequestLog
b.append('-');
}
@SuppressWarnings("unused")
private static void logRequestCookies(StringBuilder b, Request request, Response response)
{
Cookie[] cookies = request.getCookies();
@ -1068,11 +1081,13 @@ public class CustomRequestLog extends ContainerLifeCycle implements RequestLog
}
}
@SuppressWarnings("unused")
private static void logEnvironmentVar(String arg, StringBuilder b, Request request, Response response)
{
append(b, System.getenv(arg));
}
@SuppressWarnings("unused")
private static void logFilename(StringBuilder b, Request request, Response response)
{
UserIdentity.Scope scope = request.getUserIdentityScope();
@ -1087,16 +1102,19 @@ public class CustomRequestLog extends ContainerLifeCycle implements RequestLog
}
}
@SuppressWarnings("unused")
private static void logRequestProtocol(StringBuilder b, Request request, Response response)
{
append(b, request.getProtocol());
}
@SuppressWarnings("unused")
private static void logRequestHeader(String arg, StringBuilder b, Request request, Response response)
{
append(b, request.getHeader(arg));
}
@SuppressWarnings("unused")
private static void logKeepAliveRequests(StringBuilder b, Request request, Response response)
{
long requests = request.getHttpChannel().getConnection().getMessagesIn();
@ -1106,21 +1124,25 @@ public class CustomRequestLog extends ContainerLifeCycle implements RequestLog
b.append('-');
}
@SuppressWarnings("unused")
private static void logRequestMethod(StringBuilder b, Request request, Response response)
{
append(b, request.getMethod());
}
@SuppressWarnings("unused")
private static void logResponseHeader(String arg, StringBuilder b, Request request, Response response)
{
append(b, response.getHeader(arg));
}
@SuppressWarnings("unused")
private static void logQueryString(StringBuilder b, Request request, Response response)
{
append(b, "?" + request.getQueryString());
}
@SuppressWarnings("unused")
private static void logRequestFirstLine(StringBuilder b, Request request, Response response)
{
append(b, request.getMethod());
@ -1130,17 +1152,19 @@ public class CustomRequestLog extends ContainerLifeCycle implements RequestLog
append(b, request.getProtocol());
}
@SuppressWarnings("unused")
private static void logRequestHandler(StringBuilder b, Request request, Response response)
{
append(b, request.getServletName());
}
@SuppressWarnings("unused")
private static void logResponseStatus(StringBuilder b, Request request, Response response)
{
//todo can getCommittedMetaData be null? check what happens when its aborted
b.append(response.getCommittedMetaData().getStatus());
}
@SuppressWarnings("unused")
private static void logRequestTime(DateCache dateCache, StringBuilder b, Request request, Response response)
{
b.append('[');
@ -1148,6 +1172,7 @@ public class CustomRequestLog extends ContainerLifeCycle implements RequestLog
b.append(']');
}
@SuppressWarnings("unused")
private static void logLatencyMicroseconds(StringBuilder b, Request request, Response response)
{
long currentTime = System.currentTimeMillis();
@ -1159,38 +1184,45 @@ public class CustomRequestLog extends ContainerLifeCycle implements RequestLog
b.append(latencyUs);
}
@SuppressWarnings("unused")
private static void logLatencyMilliseconds(StringBuilder b, Request request, Response response)
{
long latency = System.currentTimeMillis() - request.getTimeStamp();
b.append(latency);
}
@SuppressWarnings("unused")
private static void logLatencySeconds(StringBuilder b, Request request, Response response)
{
long latency = System.currentTimeMillis() - request.getTimeStamp();
b.append(TimeUnit.MILLISECONDS.toSeconds(latency));
}
@SuppressWarnings("unused")
private static void logRequestAuthentication(StringBuilder b, Request request, Response response)
{
append(b, getAuthentication(request, false));
}
@SuppressWarnings("unused")
private static void logRequestAuthenticationWithDeferred(StringBuilder b, Request request, Response response)
{
append(b, getAuthentication(request, true));
}
@SuppressWarnings("unused")
private static void logUrlRequestPath(StringBuilder b, Request request, Response response)
{
append(b, request.getRequestURI());
}
@SuppressWarnings("unused")
private static void logConnectionStatus(StringBuilder b, Request request, Response response)
{
b.append(request.getHttpChannel().isResponseCompleted() ? (request.getHttpChannel().isPersistent() ? '+' : '-') : 'X');
}
@SuppressWarnings("unused")
private static void logRequestTrailer(String arg, StringBuilder b, Request request, Response response)
{
HttpFields trailers = request.getTrailerHttpFields();
@ -1200,6 +1232,7 @@ public class CustomRequestLog extends ContainerLifeCycle implements RequestLog
b.append('-');
}
@SuppressWarnings("unused")
private static void logResponseTrailer(String arg, StringBuilder b, Request request, Response response)
{
Supplier<HttpFields> supplier = response.getTrailers();

View File

@ -619,6 +619,14 @@ public class HttpInput extends ServletInputStream implements Runnable
}
}
public long getContentReceived()
{
synchronized (_inputQ)
{
return _contentArrived;
}
}
/**
* This method should be called to signal that an EOF has been detected before all the expected content arrived.
* <p>

View File

@ -32,7 +32,7 @@ public class StdErrAppender implements JettyAppender
* Configuration keys specific to the StdErrAppender
*/
static final String NAME_CONDENSE_KEY = "org.eclipse.jetty.logging.appender.NAME_CONDENSE";
static final String THREAD_PADDING_KEY = "org.eclipse.jetty.logging.appender.THREAD_PADDING";
static final String MESSAGE_ALIGN_KEY = "org.eclipse.jetty.logging.appender.MESSAGE_ALIGN";
static final String MESSAGE_ESCAPE_KEY = "org.eclipse.jetty.logging.appender.MESSAGE_ESCAPE";
static final String ZONEID_KEY = "org.eclipse.jetty.logging.appender.ZONE_ID";
private static final String EOL = System.lineSeparator();
@ -50,9 +50,9 @@ public class StdErrAppender implements JettyAppender
private final boolean escapedMessages;
/**
* The fixed size of the thread name to use for output
* The column to align the start of all messages to
*/
private final int threadPadding;
private final int messageAlignColumn;
/**
* The stream to write logging events to.
@ -88,7 +88,7 @@ public class StdErrAppender implements JettyAppender
this.condensedNames = config.getBoolean(NAME_CONDENSE_KEY, true);
this.escapedMessages = config.getBoolean(MESSAGE_ESCAPE_KEY, true);
this.threadPadding = config.getInt(THREAD_PADDING_KEY, -1);
this.messageAlignColumn = config.getInt(MESSAGE_ALIGN_KEY, 0);
}
@Override
@ -116,9 +116,9 @@ public class StdErrAppender implements JettyAppender
return escapedMessages;
}
public int getThreadPadding()
public int getMessageAlignColumn()
{
return threadPadding;
return messageAlignColumn;
}
public PrintStream getStream()
@ -154,11 +154,15 @@ public class StdErrAppender implements JettyAppender
// Thread Name
builder.append(':');
builder.append(threadName); // TODO: support TAG_PAD configuration
builder.append(threadName);
builder.append(':');
// Message
builder.append(' ');
int padAmount = messageAlignColumn - builder.length();
if (padAmount > 0)
builder.append(" ".repeat(padAmount));
else
builder.append(' ');
FormattingTuple ft = MessageFormatter.arrayFormat(message, argumentArray);
appendEscaped(builder, ft.getMessage());

View File

@ -34,7 +34,7 @@ public class JettyLoggerConfigurationTest
Properties props = new Properties();
props.setProperty(StdErrAppender.MESSAGE_ESCAPE_KEY, "false");
props.setProperty(StdErrAppender.NAME_CONDENSE_KEY, "false");
props.setProperty(StdErrAppender.THREAD_PADDING_KEY, "10");
props.setProperty(StdErrAppender.MESSAGE_ALIGN_KEY, "10");
props.setProperty("com.mortbay.LEVEL", "WARN");
props.setProperty("com.mortbay.STACKS", "false");
@ -43,7 +43,7 @@ public class JettyLoggerConfigurationTest
assertFalse(appender.isEscapedMessages());
assertFalse(appender.isCondensedNames());
assertEquals(appender.getThreadPadding(), 10);
assertEquals(appender.getMessageAlignColumn(), 10);
JettyLevel level = config.getLevel("com.mortbay");
assertEquals(JettyLevel.WARN, level);

View File

@ -162,6 +162,57 @@ public class JettyLoggerTest
output.assertContains("Message with ? escape");
}
@Test
public void testStdErrLogMessageAlignment()
{
Properties props = new Properties();
props.setProperty(StdErrAppender.MESSAGE_ALIGN_KEY, "50");
JettyLoggerConfiguration config = new JettyLoggerConfiguration(props);
JettyLoggerFactory factory = new JettyLoggerFactory(config);
StdErrAppender appender = (StdErrAppender)factory.getRootLogger().getAppender();
CapturedStream output = new CapturedStream();
appender.setStream(output);
JettyLogger logJetty = factory.getJettyLogger("jetty");
JettyLogger logJettyDeep = factory.getJettyLogger("jetty.from.deep");
JettyLogger logJettyDeeper = factory.getJettyLogger("jetty.component.deeper.still");
logJetty.setLevel(JettyLevel.DEBUG);
logJettyDeep.debug("testing {} {}", "test", "debug");
logJettyDeep.info("testing {} {}", "test", "info");
logJettyDeep.warn("testing {} {}", "test", "warn");
logJettyDeeper.debug("testing {} {}", "test", "debug");
logJettyDeeper.info("testing {} {}", "test", "info");
logJettyDeeper.warn("testing {} {}", "test", "warn");
Thread.currentThread().setName("otherThread");
logJetty.info("testing {} {}", "test", "info");
logJettyDeep.info("testing {} {}", "test", "info");
logJettyDeeper.info("testing {} {}", "test", "info");
Thread.currentThread().setName("veryLongThreadName");
logJetty.info("testing {} {}", "test", "info");
logJettyDeep.info("testing {} {}", "test", "info");
logJettyDeeper.info("testing {} {}", "test", "info");
output.assertContains("DEBUG:jf.deep:tname: testing test debug");
output.assertContains("INFO :jf.deep:tname: testing test info");
output.assertContains("WARN :jf.deep:tname: testing test warn");
output.assertContains("DEBUG:jcd.still:tname: testing test debug");
output.assertContains("INFO :jcd.still:tname: testing test info");
output.assertContains("WARN :jcd.still:tname: testing test warn");
output.assertContains("INFO :jetty:otherThread: testing test info");
output.assertContains("INFO :jf.deep:otherThread: testing test info");
output.assertContains("INFO :jcd.still:otherThread: testing test info");
output.assertContains("INFO :jetty:veryLongThreadName: testing test info");
output.assertContains("INFO :jf.deep:veryLongThreadName: testing test info");
output.assertContains("INFO :jcd.still:veryLongThreadName: testing test info");
}
/**
* Test to make sure that using a Null parameter on parameterized messages does not result in a NPE
*/

View File

@ -0,0 +1,86 @@
//
// ========================================================================
// Copyright (c) 1995-2020 Mort Bay Consulting Pty Ltd and others.
//
// This program and the accompanying materials are made available under
// the terms of the Eclipse Public License 2.0 which is available at
// https://www.eclipse.org/legal/epl-2.0
//
// This Source Code may also be made available under the following
// Secondary Licenses when the conditions for such availability set
// forth in the Eclipse Public License, v. 2.0 are satisfied:
// the Apache License v2.0 which is available at
// https://www.apache.org/licenses/LICENSE-2.0
//
// SPDX-License-Identifier: EPL-2.0 OR Apache-2.0
// ========================================================================
//
package org.eclipse.jetty.logging.jmh;
import java.util.concurrent.TimeUnit;
import org.openjdk.jmh.annotations.Benchmark;
import org.openjdk.jmh.annotations.BenchmarkMode;
import org.openjdk.jmh.annotations.Measurement;
import org.openjdk.jmh.annotations.Mode;
import org.openjdk.jmh.annotations.Scope;
import org.openjdk.jmh.annotations.State;
import org.openjdk.jmh.annotations.Threads;
import org.openjdk.jmh.annotations.Warmup;
import org.openjdk.jmh.infra.Blackhole;
import org.openjdk.jmh.profile.GCProfiler;
import org.openjdk.jmh.runner.Runner;
import org.openjdk.jmh.runner.RunnerException;
import org.openjdk.jmh.runner.options.Options;
import org.openjdk.jmh.runner.options.OptionsBuilder;
@State(Scope.Benchmark)
@Threads(4)
@Warmup(iterations = 7, time = 500, timeUnit = TimeUnit.MILLISECONDS)
@Measurement(iterations = 7, time = 500, timeUnit = TimeUnit.MILLISECONDS)
public class IndentBenchmark
{
private static final int SMALL = 13;
private static final int LARGE = 43;
private String bigstring = " ";
@Benchmark
@BenchmarkMode(Mode.Throughput)
public void testStringSubStringSmall(Blackhole blackhole)
{
blackhole.consume(bigstring.substring(0, SMALL));
}
@Benchmark
@BenchmarkMode(Mode.Throughput)
public void testStringSubStringLarge(Blackhole blackhole)
{
blackhole.consume(bigstring.substring(0, LARGE));
}
@Benchmark
@BenchmarkMode(Mode.Throughput)
public void testStringRepeatSmall(Blackhole blackhole)
{
blackhole.consume(" ".repeat(SMALL));
}
@Benchmark
@BenchmarkMode(Mode.Throughput)
public void testStringRepeatLarge(Blackhole blackhole)
{
blackhole.consume(" ".repeat(LARGE));
}
public static void main(String[] args) throws RunnerException
{
Options opt = new OptionsBuilder()
.include(IndentBenchmark.class.getSimpleName())
.addProfiler(GCProfiler.class)
.forks(1)
.build();
new Runner(opt).run();
}
}