From e04731ac24047a7d48fa759fa90c5d45512cb7ca Mon Sep 17 00:00:00 2001 From: David Schlosnagle Date: Tue, 9 May 2017 17:25:26 -0400 Subject: [PATCH] Optimize hot paths for JIT compilation (#9) Analyzed several hot paths via JIT Watch and optimized to enable better JIT compilation and inlining. --- .../CompositeInvocationEventHandler.java | 27 ++++---- .../event/DefaultInvocationContext.java | 18 +++-- .../tritium/proxy/InvocationEventProxy.java | 10 +-- .../log/LoggingInvocationEventHandler.java | 67 ++++++++++--------- 4 files changed, 69 insertions(+), 53 deletions(-) diff --git a/tritium-core/src/main/java/com/palantir/tritium/event/CompositeInvocationEventHandler.java b/tritium-core/src/main/java/com/palantir/tritium/event/CompositeInvocationEventHandler.java index 3e06eb747..79d5ea88e 100644 --- a/tritium-core/src/main/java/com/palantir/tritium/event/CompositeInvocationEventHandler.java +++ b/tritium-core/src/main/java/com/palantir/tritium/event/CompositeInvocationEventHandler.java @@ -106,10 +106,18 @@ private static InvocationContext handlePreInvocation(InvocationEventHandler handler, + Object instance, Method method, Object[] args, Exception exception) { + LOGGER.warn("Exception handling preInvocation({}): " + + "invocation of {}.{} with arguments {} on {} threw: {}", + handler, + method.getDeclaringClass().getCanonicalName(), method.getName(), Arrays.toString(args), instance, + exception, exception); } private void handleSuccess(InvocationEventHandler handler, @@ -120,7 +128,7 @@ private void handleSuccess(InvocationEventHandler handler, handler.onSuccess(context, result); } catch (RuntimeException e) { LOGGER.warn("Exception handling onSuccess({}, {}): {}", - context, result, e.toString(), e); + context, result, e, e); } } @@ -132,19 +140,10 @@ private void handleFailure(InvocationEventHandler handler, handler.onFailure(context, cause); } catch (RuntimeException e) { LOGGER.warn("Exception handling onFailure({}, {}): {}", - context, cause, e.toString(), e); + context, cause, e, e); } } - protected static String toInvocationDebugString(InvocationEventHandler handler, - Object instance, - Method method, - Object[] args) { - return "invocation of " + handler + " on " + instance + " : " - + method.getDeclaringClass() + '.' + method.getName() - + " with arguments " + Arrays.toString(args); - } - static class CompositeInvocationContext extends DefaultInvocationContext { private final InvocationContext[] contexts; diff --git a/tritium-core/src/main/java/com/palantir/tritium/event/DefaultInvocationContext.java b/tritium-core/src/main/java/com/palantir/tritium/event/DefaultInvocationContext.java index 9ebe1745c..11dbc84fc 100644 --- a/tritium-core/src/main/java/com/palantir/tritium/event/DefaultInvocationContext.java +++ b/tritium-core/src/main/java/com/palantir/tritium/event/DefaultInvocationContext.java @@ -25,6 +25,8 @@ public class DefaultInvocationContext implements InvocationContext { + private static final Object[] NO_ARGS = {}; + private final long startTimeNanos; private final Object instance; private final Method method; @@ -32,13 +34,21 @@ public class DefaultInvocationContext implements InvocationContext { protected DefaultInvocationContext(long startTimeNanos, Object instance, Method method, @Nullable Object[] args) { this.startTimeNanos = startTimeNanos; - this.instance = checkNotNull(instance); - this.method = checkNotNull(method); - this.args = AbstractInvocationEventHandler.nullToEmpty(args).clone(); + this.instance = instance; + this.method = method; + this.args = toNonNullClone(args); + } + + private static Object[] toNonNullClone(@Nullable Object[] args) { + return args == null ? NO_ARGS : args.clone(); } public static InvocationContext of(Object instance, Method method, @Nullable Object[] args) { - return new DefaultInvocationContext(System.nanoTime(), instance, method, args); + return new DefaultInvocationContext( + System.nanoTime(), + checkNotNull(instance, "instance"), + checkNotNull(method, "method"), + args); } @Override diff --git a/tritium-lib/src/main/java/com/palantir/tritium/proxy/InvocationEventProxy.java b/tritium-lib/src/main/java/com/palantir/tritium/proxy/InvocationEventProxy.java index 646477b36..a9a9bbd17 100644 --- a/tritium-lib/src/main/java/com/palantir/tritium/proxy/InvocationEventProxy.java +++ b/tritium-lib/src/main/java/com/palantir/tritium/proxy/InvocationEventProxy.java @@ -81,8 +81,8 @@ private boolean isEnabled(Object instance, Method method, Object[] args) { return eventHandler.isEnabled() && filter.shouldInstrument(instance, method, args); } catch (Throwable t) { - LOGGER.warn("Exception handling preInvocation({}): {}", - toInvocationDebugString(instance, method, args), t.toString(), t); + LOGGER.warn("Exception handling isEnabled({}): {}", + toInvocationDebugString(instance, method, args), t, t); return false; } } @@ -127,7 +127,7 @@ final InvocationContext handlePreInvocation(Object instance, Method method, Obje return eventHandler.preInvocation(instance, method, args); } catch (RuntimeException e) { LOGGER.warn("Exception handling preInvocation({}): {}", - toInvocationDebugString(instance, method, args), e.toString(), e); + toInvocationDebugString(instance, method, args), e, e); } return null; } @@ -147,7 +147,7 @@ final Object handleOnSuccess(@Nullable InvocationContext context, @Nullable Obje eventHandler.onSuccess(context, result); } catch (RuntimeException e) { LOGGER.warn("Exception handling onSuccess({}, {}): {}", - context, result, e.toString(), e); + context, result, e, e); } return result; } @@ -157,7 +157,7 @@ final Throwable handleOnFailure(@Nullable InvocationContext context, Throwable c eventHandler.onFailure(context, cause); } catch (RuntimeException e) { LOGGER.warn("Exception handling onFailure({}, {}): {}", - context, cause, e.toString(), e); + context, cause, e, e); } return cause; } diff --git a/tritium-slf4j/src/main/java/com/palantir/tritium/event/log/LoggingInvocationEventHandler.java b/tritium-slf4j/src/main/java/com/palantir/tritium/event/log/LoggingInvocationEventHandler.java index 4956d0a3a..6eee94106 100644 --- a/tritium-slf4j/src/main/java/com/palantir/tritium/event/log/LoggingInvocationEventHandler.java +++ b/tritium-slf4j/src/main/java/com/palantir/tritium/event/log/LoggingInvocationEventHandler.java @@ -99,7 +99,6 @@ public final void onFailure(@Nullable InvocationContext context, @Nonnull Throwa return; } - LOGGER.warn("Failed {}", cause, cause); long durationNanos = System.nanoTime() - context.getStartTimeNanos(); logInvocation(context.getMethod(), context.getArgs(), durationNanos); } @@ -107,45 +106,53 @@ public final void onFailure(@Nullable InvocationContext context, @Nonnull Throwa private void logInvocation(Method method, @Nullable Object[] nullableArgs, long durationNanos) { if (isEnabled() && durationPredicate.test(durationNanos)) { Object[] args = nullToEmpty(nullableArgs); - String messagePattern = getMessagePattern(args); - Object[] logParams = getLogParams(method, args, durationNanos, level); - log(messagePattern, logParams); + log(getMessagePattern(args), getLogParams(method, args, durationNanos, level)); } } - private void log(String message, Object... args) { - if (level == LoggingLevel.TRACE) { - logger.trace(message, args); - } else if (level == LoggingLevel.DEBUG) { - logger.debug(message, args); - } else if (level == LoggingLevel.INFO) { - logger.info(message, args); - } else if (level == LoggingLevel.WARN) { - logger.warn(message, args); - } else if (level == LoggingLevel.ERROR) { - logger.error(message, args); - } else { - throw new IllegalArgumentException("Unsupported logging level " + level); + void log(String message, Object... args) { + switch (level) { + case TRACE: + logger.trace(message, args); + return; + case DEBUG: + logger.debug(message, args); + return; + case INFO: + logger.info(message, args); + return; + case WARN: + logger.warn(message, args); + return; + case ERROR: + logger.error(message, args); + return; + default: + throw invalidLoggingLevel(level); } } static boolean isEnabled(Logger logger, LoggingLevel level) { - checkNotNull(level); - if (level == LoggingLevel.TRACE) { - return logger.isTraceEnabled(); - } else if (level == LoggingLevel.DEBUG) { - return logger.isDebugEnabled(); - } else if (level == LoggingLevel.INFO) { - return logger.isInfoEnabled(); - } else if (level == LoggingLevel.WARN) { - return logger.isWarnEnabled(); - } else if (level == LoggingLevel.ERROR) { - return logger.isErrorEnabled(); - } else { - throw new IllegalArgumentException("Unsupported logging level " + level); + switch (level) { + case TRACE: + return logger.isTraceEnabled(); + case DEBUG: + return logger.isDebugEnabled(); + case INFO: + return logger.isInfoEnabled(); + case WARN: + return logger.isWarnEnabled(); + case ERROR: + return logger.isErrorEnabled(); + default: + throw invalidLoggingLevel(level); } } + private static IllegalArgumentException invalidLoggingLevel(LoggingLevel level) { + return new IllegalArgumentException("Unsupported logging level " + level); + } + private static BooleanSupplier createEnabledSupplier(final Logger logger, final LoggingLevel level) { checkNotNull(logger, "logger"); checkNotNull(level, "level");