From 5a1f9ab13242e256f7d1fc2c6d82cfb198d78159 Mon Sep 17 00:00:00 2001 From: Arpit Mohan Date: Tue, 27 Aug 2019 06:25:29 +0000 Subject: [PATCH] Adding MDC logging via RequestIdFilter and MDCFilter This ensures that we can send header values and those will be printed in the logs. In the class MDCFilter, we are adding the logContext to the reactive logger along with the normal MDC logger as well. --- .../server/controllers/BaseController.java | 13 +-- .../server/controllers/PluginController.java | 6 +- .../server/controllers/QueryController.java | 6 +- .../mobtools/server/domains/BaseDomain.java | 6 +- .../server/dtos/AuthenticationDTO.java | 6 +- .../com/mobtools/server/dtos/ResponseDto.java | 6 +- .../mobtools/server/filters/MDCFilter.java | 66 ++++++++++++++++ .../server/filters/RequestIdFilter.java | 34 ++++++++ .../mobtools/server/helpers/LogHelper.java | 79 +++++++++++++++++++ .../plugins/PostgresDBPluginExecutor.java | 7 +- .../mobtools/server/services/BaseService.java | 3 +- .../server/services/TenantServiceImpl.java | 1 + .../resources/application-local.properties | 2 + .../resources/application-staging.properties | 2 + 14 files changed, 199 insertions(+), 38 deletions(-) create mode 100644 app/server/src/main/java/com/mobtools/server/filters/MDCFilter.java create mode 100644 app/server/src/main/java/com/mobtools/server/filters/RequestIdFilter.java create mode 100644 app/server/src/main/java/com/mobtools/server/helpers/LogHelper.java diff --git a/app/server/src/main/java/com/mobtools/server/controllers/BaseController.java b/app/server/src/main/java/com/mobtools/server/controllers/BaseController.java index 789b77b242..a8bfbe2122 100644 --- a/app/server/src/main/java/com/mobtools/server/controllers/BaseController.java +++ b/app/server/src/main/java/com/mobtools/server/controllers/BaseController.java @@ -5,19 +5,16 @@ import com.mobtools.server.dtos.ResponseDto; import com.mobtools.server.exceptions.MobtoolsException; import com.mobtools.server.services.CrudService; import lombok.RequiredArgsConstructor; +import lombok.extern.slf4j.Slf4j; import org.springframework.http.HttpStatus; -import org.springframework.web.bind.annotation.GetMapping; -import org.springframework.web.bind.annotation.PathVariable; -import org.springframework.web.bind.annotation.PostMapping; -import org.springframework.web.bind.annotation.PutMapping; -import org.springframework.web.bind.annotation.RequestBody; -import org.springframework.web.bind.annotation.ResponseStatus; +import org.springframework.web.bind.annotation.*; import reactor.core.publisher.Flux; import reactor.core.publisher.Mono; import javax.validation.Valid; @RequiredArgsConstructor +@Slf4j public abstract class BaseController { protected final S service; @@ -25,24 +22,28 @@ public abstract class BaseController> create(@Valid @RequestBody T resource) throws MobtoolsException { + log.debug("Going to create resource {}", resource.getClass().getName()); return service.create(resource) .map(created -> new ResponseDto<>(HttpStatus.CREATED.value(), created, null)); } @GetMapping("") public Flux> getAll() { + log.debug("Going to get all resources"); return service.get() .map(resources -> new ResponseDto<>(HttpStatus.OK.value(), resources, null)); } @GetMapping("/{id}") public Mono> getById(@PathVariable ID id) { + log.debug("Going to get resource for id: {}", id); return service.getById(id) .map(resources -> new ResponseDto<>(HttpStatus.OK.value(), resources, null)); } @PutMapping("/{id}") public Mono> update(@PathVariable ID id, @RequestBody T resource) throws Exception { + log.debug("Going to update resource with id: {}", id); return service.update(id, resource) .map(updatedResource -> new ResponseDto<>(HttpStatus.OK.value(), updatedResource, null)); } diff --git a/app/server/src/main/java/com/mobtools/server/controllers/PluginController.java b/app/server/src/main/java/com/mobtools/server/controllers/PluginController.java index ef40f2eb35..08c4a845a6 100644 --- a/app/server/src/main/java/com/mobtools/server/controllers/PluginController.java +++ b/app/server/src/main/java/com/mobtools/server/controllers/PluginController.java @@ -8,11 +8,7 @@ import com.mobtools.server.dtos.ResponseDto; import com.mobtools.server.services.PluginService; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.http.HttpStatus; -import org.springframework.web.bind.annotation.PostMapping; -import org.springframework.web.bind.annotation.RequestBody; -import org.springframework.web.bind.annotation.RequestMapping; -import org.springframework.web.bind.annotation.ResponseStatus; -import org.springframework.web.bind.annotation.RestController; +import org.springframework.web.bind.annotation.*; import reactor.core.publisher.Mono; import javax.validation.Valid; diff --git a/app/server/src/main/java/com/mobtools/server/controllers/QueryController.java b/app/server/src/main/java/com/mobtools/server/controllers/QueryController.java index e4c2d66995..3645b1e591 100644 --- a/app/server/src/main/java/com/mobtools/server/controllers/QueryController.java +++ b/app/server/src/main/java/com/mobtools/server/controllers/QueryController.java @@ -5,11 +5,7 @@ import com.mobtools.server.domains.Query; import com.mobtools.server.dtos.CommandQueryParams; import com.mobtools.server.services.QueryService; import org.springframework.beans.factory.annotation.Autowired; -import org.springframework.web.bind.annotation.PathVariable; -import org.springframework.web.bind.annotation.PostMapping; -import org.springframework.web.bind.annotation.RequestBody; -import org.springframework.web.bind.annotation.RequestMapping; -import org.springframework.web.bind.annotation.RestController; +import org.springframework.web.bind.annotation.*; import reactor.core.publisher.Flux; @RestController diff --git a/app/server/src/main/java/com/mobtools/server/domains/BaseDomain.java b/app/server/src/main/java/com/mobtools/server/domains/BaseDomain.java index 7fa95fbcdf..5db5e9e9b2 100644 --- a/app/server/src/main/java/com/mobtools/server/domains/BaseDomain.java +++ b/app/server/src/main/java/com/mobtools/server/domains/BaseDomain.java @@ -3,11 +3,7 @@ package com.mobtools.server.domains; import lombok.Getter; import lombok.Setter; import lombok.ToString; -import org.springframework.data.annotation.CreatedBy; -import org.springframework.data.annotation.CreatedDate; -import org.springframework.data.annotation.Id; -import org.springframework.data.annotation.LastModifiedBy; -import org.springframework.data.annotation.LastModifiedDate; +import org.springframework.data.annotation.*; import org.springframework.data.domain.Persistable; import java.util.Date; diff --git a/app/server/src/main/java/com/mobtools/server/dtos/AuthenticationDTO.java b/app/server/src/main/java/com/mobtools/server/dtos/AuthenticationDTO.java index fd5f76b4e9..6ed8047570 100644 --- a/app/server/src/main/java/com/mobtools/server/dtos/AuthenticationDTO.java +++ b/app/server/src/main/java/com/mobtools/server/dtos/AuthenticationDTO.java @@ -1,10 +1,6 @@ package com.mobtools.server.dtos; -import lombok.AllArgsConstructor; -import lombok.Getter; -import lombok.NoArgsConstructor; -import lombok.Setter; -import lombok.ToString; +import lombok.*; @Getter @Setter diff --git a/app/server/src/main/java/com/mobtools/server/dtos/ResponseDto.java b/app/server/src/main/java/com/mobtools/server/dtos/ResponseDto.java index 6e30474cd3..6e5ae2edcb 100644 --- a/app/server/src/main/java/com/mobtools/server/dtos/ResponseDto.java +++ b/app/server/src/main/java/com/mobtools/server/dtos/ResponseDto.java @@ -1,10 +1,6 @@ package com.mobtools.server.dtos; -import lombok.AllArgsConstructor; -import lombok.Getter; -import lombok.NoArgsConstructor; -import lombok.Setter; -import lombok.ToString; +import lombok.*; import java.io.Serializable; diff --git a/app/server/src/main/java/com/mobtools/server/filters/MDCFilter.java b/app/server/src/main/java/com/mobtools/server/filters/MDCFilter.java new file mode 100644 index 0000000000..44bde1f43f --- /dev/null +++ b/app/server/src/main/java/com/mobtools/server/filters/MDCFilter.java @@ -0,0 +1,66 @@ +package com.mobtools.server.filters; + +import com.mobtools.server.helpers.LogHelper; +import org.slf4j.MDC; +import org.springframework.http.HttpHeaders; +import org.springframework.http.server.reactive.ServerHttpRequest; +import org.springframework.http.server.reactive.ServerHttpResponse; +import org.springframework.stereotype.Component; +import org.springframework.web.server.ServerWebExchange; +import org.springframework.web.server.WebFilter; +import org.springframework.web.server.WebFilterChain; +import reactor.core.publisher.Mono; +import reactor.util.context.Context; + +import java.util.Map; + +import static java.util.stream.Collectors.toMap; + +/** + * This class parses all headers that start with X-MDC-* and set them in the logger MDC. + * These MDC parameters are also set in the response object before being sent to the user. + */ +@Component +public class MDCFilter implements WebFilter { + + private static final String MDC_HEADER_PREFIX = "X-MDC-"; + + @Override + public Mono filter(ServerWebExchange exchange, WebFilterChain chain) { + try { + // Using beforeCommit here ensures that the function `addContextToHttpResponse` isn't run immediately + // It is only run when the response object is being created + exchange.getResponse().beforeCommit(() -> addContextToHttpResponse(exchange.getResponse())); + return chain.filter(exchange).subscriberContext(ctx -> addRequestHeadersToContext(exchange.getRequest(), ctx)); + } finally { + MDC.clear(); + } + } + + private Context addRequestHeadersToContext(final ServerHttpRequest request, final Context context) { + final Map contextMap = request.getHeaders().toSingleValueMap().entrySet() + .stream() + .filter(x -> x.getKey().startsWith(MDC_HEADER_PREFIX)) + .collect(toMap(v -> v.getKey().substring((MDC_HEADER_PREFIX.length())), Map.Entry::getValue)); + + // Set the MDC context here for regular non-reactive logs + MDC.setContextMap(contextMap); + + // Setting the context map to the reactive context. This will be used in the reactive logger to print the MDC + return context.put(LogHelper.CONTEXT_MAP, contextMap); + } + + private Mono addContextToHttpResponse(final ServerHttpResponse response) { + return Mono.subscriberContext().doOnNext(ctx -> { + if(!ctx.hasKey(LogHelper.CONTEXT_MAP)) { + return; + } + + final HttpHeaders httpHeaders = response.getHeaders(); + // Add all the request MDC keys to the response object + ctx.>get(LogHelper.CONTEXT_MAP) + .forEach((key, value) -> httpHeaders.add(MDC_HEADER_PREFIX + key, value)); + }).then(); + } +} + diff --git a/app/server/src/main/java/com/mobtools/server/filters/RequestIdFilter.java b/app/server/src/main/java/com/mobtools/server/filters/RequestIdFilter.java new file mode 100644 index 0000000000..cd47aab5bb --- /dev/null +++ b/app/server/src/main/java/com/mobtools/server/filters/RequestIdFilter.java @@ -0,0 +1,34 @@ +package com.mobtools.server.filters; + +import com.mobtools.server.helpers.LogHelper; +import lombok.extern.slf4j.Slf4j; +import org.springframework.stereotype.Component; +import org.springframework.web.server.ServerWebExchange; +import org.springframework.web.server.WebFilter; +import org.springframework.web.server.WebFilterChain; +import reactor.core.publisher.Mono; + +import java.util.UUID; + +/** + * This class specifically parses the requestId key from the headers and sets it in the logger MDC + */ +@Slf4j +@Component +public class RequestIdFilter implements WebFilter { + + private static final String REQUEST_ID_HEADER = "X-REQUEST-ID"; + private static final String REQUEST_ID_LOG = "requestId"; + + @Override + public Mono filter(ServerWebExchange exchange, WebFilterChain chain) { + + if (!exchange.getRequest().getHeaders().containsKey(REQUEST_ID_HEADER)) { + exchange.getRequest().mutate().header(REQUEST_ID_HEADER, UUID.randomUUID().toString()).build(); + } + + String header = exchange.getRequest().getHeaders().get(REQUEST_ID_HEADER).get(0); + log.debug("Setting the requestId header to {}", header); + return chain.filter(exchange).subscriberContext(LogHelper.putLogContext(REQUEST_ID_LOG, header)); + } +} diff --git a/app/server/src/main/java/com/mobtools/server/helpers/LogHelper.java b/app/server/src/main/java/com/mobtools/server/helpers/LogHelper.java new file mode 100644 index 0000000000..d98b4c1eea --- /dev/null +++ b/app/server/src/main/java/com/mobtools/server/helpers/LogHelper.java @@ -0,0 +1,79 @@ +package com.mobtools.server.helpers; + +import org.slf4j.MDC; +import reactor.core.publisher.Signal; +import reactor.core.publisher.SignalType; +import reactor.util.context.Context; + +import java.util.HashMap; +import java.util.Map; +import java.util.Optional; +import java.util.function.Consumer; +import java.util.function.Function; + +public class LogHelper { + + public static final String CONTEXT_MAP = "context-map"; + + public static Function putLogContext(String key, String value) { + return ctx -> { + Optional> optionalContextMap = ctx.getOrEmpty(CONTEXT_MAP); + + if (optionalContextMap.isPresent()) { + optionalContextMap.get().put(key, value); + return ctx; + } + + Map ctxMap = new HashMap<>(); + ctxMap.put(key, value); + + return ctx.put(CONTEXT_MAP, ctxMap); + }; + } + + public static Consumer> logOnNext(Consumer log) { + return signal -> { + if (signal.getType() != SignalType.ON_NEXT) { + return; + } + + Optional> maybeContextMap = signal.getContext().getOrEmpty(CONTEXT_MAP); + + if (!maybeContextMap.isPresent()) { + log.accept(signal.get()); + return; + } + + MDC.setContextMap(maybeContextMap.get()); + try { + log.accept(signal.get()); + } finally { + MDC.clear(); + } + }; + } + + public static Consumer> logOnError(Consumer log) { + return signal -> { + if (!signal.isOnError()) { + return; + } + + Optional> maybeContextMap + = signal.getContext().getOrEmpty(CONTEXT_MAP); + + if (!maybeContextMap.isPresent()) { + log.accept(signal.getThrowable()); + return; + } + + MDC.setContextMap(maybeContextMap.get()); + try { + log.accept(signal.getThrowable()); + } finally { + MDC.clear(); + } + }; + } + +} diff --git a/app/server/src/main/java/com/mobtools/server/plugins/PostgresDBPluginExecutor.java b/app/server/src/main/java/com/mobtools/server/plugins/PostgresDBPluginExecutor.java index 7bd440ba57..365b54f1c3 100644 --- a/app/server/src/main/java/com/mobtools/server/plugins/PostgresDBPluginExecutor.java +++ b/app/server/src/main/java/com/mobtools/server/plugins/PostgresDBPluginExecutor.java @@ -8,12 +8,7 @@ import org.springframework.beans.factory.annotation.Value; import org.springframework.stereotype.Component; import reactor.core.publisher.Flux; -import java.sql.Connection; -import java.sql.DriverManager; -import java.sql.ResultSet; -import java.sql.ResultSetMetaData; -import java.sql.SQLException; -import java.sql.Statement; +import java.sql.*; import java.util.ArrayList; import java.util.HashMap; diff --git a/app/server/src/main/java/com/mobtools/server/services/BaseService.java b/app/server/src/main/java/com/mobtools/server/services/BaseService.java index 3bd1d7b07e..5d13c8a98a 100644 --- a/app/server/src/main/java/com/mobtools/server/services/BaseService.java +++ b/app/server/src/main/java/com/mobtools/server/services/BaseService.java @@ -62,7 +62,8 @@ public abstract class BaseService getById(ID id) { - return repository.findById(id); + return repository.findById(id) + .switchIfEmpty(Mono.error(new MobtoolsException("Unable to find resource with id: " + id.toString()))); } @Override diff --git a/app/server/src/main/java/com/mobtools/server/services/TenantServiceImpl.java b/app/server/src/main/java/com/mobtools/server/services/TenantServiceImpl.java index 94bb826cbc..ec43ff1598 100644 --- a/app/server/src/main/java/com/mobtools/server/services/TenantServiceImpl.java +++ b/app/server/src/main/java/com/mobtools/server/services/TenantServiceImpl.java @@ -48,6 +48,7 @@ public class TenantServiceImpl extends BaseService create(Tenant tenant) { + log.debug("Going to create the tenant"); return Mono.just(tenant) //transform the tenant data to embed setting object in each object in tenantSetting list. .flatMap(this::enhanceTenantSettingList) diff --git a/app/server/src/main/resources/application-local.properties b/app/server/src/main/resources/application-local.properties index fcadf3f47b..7bb61fc71f 100644 --- a/app/server/src/main/resources/application-local.properties +++ b/app/server/src/main/resources/application-local.properties @@ -5,7 +5,9 @@ spring.data.mongodb.port=27017 #spring.data.mongodb.username= #spring.data.mongodb.password= +logging.level.root=info logging.level.com.mobtools=debug +logging.pattern.console=%X - %m%n # JDBC Postgres properties jdbc.postgres.driver=org.postgresql.Driver diff --git a/app/server/src/main/resources/application-staging.properties b/app/server/src/main/resources/application-staging.properties index bba56a1d52..24ed53f6dc 100644 --- a/app/server/src/main/resources/application-staging.properties +++ b/app/server/src/main/resources/application-staging.properties @@ -3,7 +3,9 @@ spring.data.mongodb.database=mobtools spring.data.mongodb.uri=mongodb+srv://admin:Y9PuxM52gcP3Dgfo@mobtools-test-cluster-swrsq.mongodb.net/mobtools?retryWrites=true spring.data.mongodb.authentication-database=admin +logging.level.root=info logging.level.com.mobtools=debug +logging.pattern.console=%X - %m%n # JDBC Postgres properties jdbc.postgres.driver=org.postgresql.Driver