From dfe6e1fe49756fd444b8c8b1981fccfe0bd3cc4f Mon Sep 17 00:00:00 2001 From: myrle-krantz Date: Wed, 31 May 2017 13:18:14 +0200 Subject: [PATCH] Added optional logging for command handlers. Default is off. --- .../command/annotation/CommandHandler.java | 9 ++--- .../command/annotation/CommandLogLevel.java | 33 +++++++++++++++ .../command/domain/CommandHandlerHolder.java | 20 +++++++++- .../core/command/internal/CommandBus.java | 40 ++++++++++++++++++- 4 files changed, 93 insertions(+), 9 deletions(-) create mode 100644 src/main/java/io/mifos/core/command/annotation/CommandLogLevel.java diff --git a/src/main/java/io/mifos/core/command/annotation/CommandHandler.java b/src/main/java/io/mifos/core/command/annotation/CommandHandler.java index 8b57ae3..e1db3e3 100644 --- a/src/main/java/io/mifos/core/command/annotation/CommandHandler.java +++ b/src/main/java/io/mifos/core/command/annotation/CommandHandler.java @@ -15,15 +15,12 @@ */ package io.mifos.core.command.annotation; -import java.lang.annotation.Documented; -import java.lang.annotation.ElementType; -import java.lang.annotation.Retention; -import java.lang.annotation.RetentionPolicy; -import java.lang.annotation.Target; +import java.lang.annotation.*; @Retention(RetentionPolicy.RUNTIME) @Target(ElementType.METHOD) @Documented public @interface CommandHandler { - + CommandLogLevel logStart() default CommandLogLevel.NONE; + CommandLogLevel logFinish() default CommandLogLevel.NONE; } diff --git a/src/main/java/io/mifos/core/command/annotation/CommandLogLevel.java b/src/main/java/io/mifos/core/command/annotation/CommandLogLevel.java new file mode 100644 index 0000000..c042c86 --- /dev/null +++ b/src/main/java/io/mifos/core/command/annotation/CommandLogLevel.java @@ -0,0 +1,33 @@ +/* + * Copyright 2017 The Mifos Initiative. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package io.mifos.core.command.annotation; + +/** + * @author Myrle Krantz + */ +public enum CommandLogLevel { + + INFO("INFO"), DEBUG("DEBUG"), TRACE("TRACE"), NONE("TRACE"); + + private final String strVal; + + CommandLogLevel(final String strVal) { + this.strVal = strVal; + } + public String toString() { + return strVal; + } +} diff --git a/src/main/java/io/mifos/core/command/domain/CommandHandlerHolder.java b/src/main/java/io/mifos/core/command/domain/CommandHandlerHolder.java index a0d4efa..33a08b5 100644 --- a/src/main/java/io/mifos/core/command/domain/CommandHandlerHolder.java +++ b/src/main/java/io/mifos/core/command/domain/CommandHandlerHolder.java @@ -16,8 +16,10 @@ package io.mifos.core.command.domain; import io.mifos.core.command.annotation.EventEmitter; +import io.mifos.core.lang.TenantContextHolder; import java.lang.reflect.Method; +import java.util.function.Consumer; public final class CommandHandlerHolder { @@ -25,14 +27,20 @@ public final class CommandHandlerHolder { private final Method method; private final EventEmitter eventEmitter; private final Class[] exceptionTypes; + private final Consumer logStart; + private final Consumer logFinish; public CommandHandlerHolder(final Object aggregate, final Method method, final EventEmitter eventEmitter, - final Class[] exceptionTypes) { + final Class[] exceptionTypes, + final Consumer logStart, + final Consumer logFinish) { super(); this.aggregate = aggregate; this.method = method; this.eventEmitter = eventEmitter; this.exceptionTypes = exceptionTypes; + this.logStart = logStart; + this.logFinish = logFinish; } public Object aggregate() { @@ -50,4 +58,14 @@ public EventEmitter eventEmitter() { public Class[] exceptionTypes() { return exceptionTypes; } + + @SuppressWarnings("OptionalUsedAsFieldOrParameterType") + public void logStart(final Object command) { + logStart.accept(command); + } + + @SuppressWarnings("OptionalUsedAsFieldOrParameterType") + public void logFinish(final Object command) { + logFinish.accept(command); + } } diff --git a/src/main/java/io/mifos/core/command/internal/CommandBus.java b/src/main/java/io/mifos/core/command/internal/CommandBus.java index 73466f7..a460be8 100644 --- a/src/main/java/io/mifos/core/command/internal/CommandBus.java +++ b/src/main/java/io/mifos/core/command/internal/CommandBus.java @@ -19,6 +19,7 @@ import io.mifos.core.cassandra.core.TenantAwareEntityTemplate; import io.mifos.core.command.annotation.Aggregate; import io.mifos.core.command.annotation.CommandHandler; +import io.mifos.core.command.annotation.CommandLogLevel; import io.mifos.core.command.annotation.EventEmitter; import io.mifos.core.command.domain.CommandHandlerHolder; import io.mifos.core.command.domain.CommandProcessingException; @@ -49,6 +50,7 @@ import java.util.Map; import java.util.concurrent.ConcurrentHashMap; import java.util.concurrent.Future; +import java.util.function.Consumer; @Component public class CommandBus implements ApplicationContextAware { @@ -83,8 +85,13 @@ public void dispatch(final C command) { CommandHandlerHolder commandHandlerHolder = null; try { commandHandlerHolder = this.findCommandHandler(command); + commandHandlerHolder.logStart(command); + final Object result = commandHandlerHolder.method().invoke(commandHandlerHolder.aggregate(), command); this.updateCommandSource(commandSource, null); + + commandHandlerHolder.logFinish(result); + if (commandHandlerHolder.eventEmitter() != null) { this.fireEvent(result, commandHandlerHolder.eventEmitter()); } @@ -103,9 +110,13 @@ public Future dispatch(final C command, final Class clazz) throws C try { // find command handling method commandHandlerHolder = this.findCommandHandler(command); + commandHandlerHolder.logStart(command); + final Object result = commandHandlerHolder.method().invoke(commandHandlerHolder.aggregate(), command); this.updateCommandSource(commandSource, null); + commandHandlerHolder.logFinish(result); + if (commandHandlerHolder.eventEmitter() != null) { this.fireEvent(result, commandHandlerHolder.eventEmitter()); } @@ -136,17 +147,42 @@ private CommandHandlerHolder findCommandHandler(final C command) { CommandHandlerHolder getCommandHandlerMethodFromClass(final Class commandClass, final Object aggregate) { final Method[] methods = aggregate.getClass().getDeclaredMethods(); for (final Method method : methods) { - if (AnnotationUtils.findAnnotation(method, CommandHandler.class) != null + final CommandHandler commandHandlerAnnotation = AnnotationUtils.findAnnotation(method, CommandHandler.class); + if (commandHandlerAnnotation != null && method.getParameterCount() == 1 && method.getParameterTypes()[0].isAssignableFrom(commandClass)) { this.logger.debug("CommandBus::findCommandHandler added method for {}.", commandClass.getSimpleName()); + + //Note that as much of the logic of determining how to log as possible is moved into the creation of the + //handler holder rather than performing it in the process of handling the command. Creation of the command + //handler holder is not performance critical, but execution of the command is. + final Consumer logStart = getLogHandler(commandHandlerAnnotation.logStart(), + "Handling command of type " + commandClass.getCanonicalName() + " for tenant {}, -> command {}"); + + final Consumer logFinish = getLogHandler(commandHandlerAnnotation.logFinish(), + "Handled command of type " + commandClass.getCanonicalName() + " for tenant {}, -> result {}"); + return new CommandHandlerHolder(aggregate, method, AnnotationUtils.findAnnotation(method, EventEmitter.class), - method.getExceptionTypes()); + method.getExceptionTypes(), logStart, logFinish); } } return null; } + private Consumer getLogHandler(final CommandLogLevel level, final String formatString) { + switch (level) { + case INFO: + return (x) -> logger.info(formatString, TenantContextHolder.identifier().orElse("none"), x); + case DEBUG: + return (x) -> logger.debug(formatString, TenantContextHolder.identifier().orElse("none"), x); + case TRACE: + return (x) -> logger.trace(formatString, TenantContextHolder.identifier().orElse("none"), x); + default: + case NONE: + return (x) -> { }; + } + } + private CommandSource storeCommand(final C command) { this.logger.debug("CommandBus::storeCommand called."); final LocalDateTime now = LocalDateTime.now();