Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 3 additions & 0 deletions build.gradle
Original file line number Diff line number Diff line change
Expand Up @@ -93,6 +93,9 @@ dependencies {

// AOP
implementation 'org.springframework.boot:spring-boot-starter-aop'

// Micrometer Prometheus
implementation 'io.micrometer:micrometer-registry-prometheus'
}

tasks.named('test') {
Expand Down
161 changes: 144 additions & 17 deletions src/main/java/doldol_server/doldol/common/config/LoggingAspect.java
Original file line number Diff line number Diff line change
Expand Up @@ -9,21 +9,33 @@
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.core.env.Environment;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;
import org.springframework.web.util.ContentCachingRequestWrapper;

import com.fasterxml.jackson.databind.ObjectMapper;

import io.micrometer.core.instrument.Counter;
import io.micrometer.core.instrument.MeterRegistry;
import io.micrometer.core.instrument.Timer;
import jakarta.servlet.http.HttpServletRequest;
import lombok.RequiredArgsConstructor;
import lombok.extern.slf4j.Slf4j;

@Slf4j
@Aspect
@Component
@RequiredArgsConstructor
public class LoggingAspect {
private final ObjectMapper objectMapper = new ObjectMapper();
private final MeterRegistry meterRegistry;

@Autowired
private Environment environment;

private static final String START_LOG = "================================================NEW===============================================\n";
private static final String END_LOG = "================================================END===============================================\n";

Expand All @@ -39,56 +51,171 @@ public void controllerErrorLevelExecute() {
public Object requestInfoLevelLogging(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
HttpServletRequest request = ((ServletRequestAttributes) RequestContextHolder.currentRequestAttributes()).getRequest();
final ContentCachingRequestWrapper cachingRequest = (ContentCachingRequestWrapper) request;

Timer.Sample sample = Timer.start(meterRegistry);
long startAt = System.currentTimeMillis();
Object returnValue = proceedingJoinPoint.proceed(proceedingJoinPoint.getArgs());
long endAt = System.currentTimeMillis();

log.info(getCommunicationData(request, cachingRequest, startAt, endAt, returnValue));
return returnValue;
try {
Object returnValue = proceedingJoinPoint.proceed(proceedingJoinPoint.getArgs());
long endAt = System.currentTimeMillis();
long responseTime = endAt - startAt;

if (isProdProfile()) {
recordMetrics(request, startAt, endAt, "SUCCESS");

log.info("REQUEST_METRICS method={} uri={} response_time_ms={} status=SUCCESS timestamp={}",
request.getMethod(),
request.getRequestURI(),
responseTime,
startAt);
}

log.info(getCommunicationData(request, cachingRequest, startAt, endAt, returnValue, null));

return returnValue;
} catch (Exception e) {
long endAt = System.currentTimeMillis();
long responseTime = endAt - startAt;

if (isProdProfile()) {
recordMetrics(request, startAt, endAt, "ERROR");

log.error("ERROR_METRICS method={} uri={} response_time_ms={} status=ERROR timestamp={} error_class={} error_message=\"{}\"",
request.getMethod(),
request.getRequestURI(),
responseTime,
startAt,
e.getClass().getSimpleName(),
e.getMessage());
}

log.error(getCommunicationData(request, cachingRequest, startAt, endAt, null, e));

throw e;
} finally {
if (isProdProfile()) {
sample.stop(Timer.builder("http_request_duration_seconds")
.tag("method", request.getMethod())
.tag("uri", getSimplifiedUri(request.getRequestURI()))
.register(meterRegistry));
}
}
}

@Around("doldol_server.doldol.common.config.LoggingAspect.controllerErrorLevelExecute()")
public Object requestErrorLevelLogging(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
HttpServletRequest request = ((ServletRequestAttributes) RequestContextHolder.currentRequestAttributes()).getRequest();
final ContentCachingRequestWrapper cachingRequest = (ContentCachingRequestWrapper) request;
long startAt = System.currentTimeMillis();

Object returnValue = proceedingJoinPoint.proceed(proceedingJoinPoint.getArgs());

long endAt = System.currentTimeMillis();
long responseTime = endAt - startAt;

log.error(getCommunicationData(request, cachingRequest, startAt, endAt, returnValue));
if (isProdProfile()) {
log.error("ERROR_METRICS method={} uri={} response_time_ms={} status=ERROR timestamp={} handler=GlobalExceptionHandler",
request.getMethod(),
request.getRequestURI(),
responseTime,
startAt);
}

log.error(getCommunicationData(request, cachingRequest, startAt, endAt, returnValue, null));
return returnValue;
}

private String getCommunicationData(
HttpServletRequest request,
ContentCachingRequestWrapper cachingRequest,
long startAt,
long endAt,
Object returnValue
HttpServletRequest request,
ContentCachingRequestWrapper cachingRequest,
long startAt,
long endAt,
Object returnValue,
Exception exception
) throws IOException {
StringBuilder sb = new StringBuilder();

sb.append(START_LOG);
sb.append(String.format("====> Request: %s %s ({%d}ms)\n====> *Header = {%s}\n", request.getMethod(), request.getRequestURL(), endAt - startAt, getHeaders(request)));
sb.append("=================> content type is ").append(request.getContentType()).append("\n");
if ("POST".equalsIgnoreCase(request.getMethod())) {
sb.append(String.format("====> application/json Body: {%s}\n", objectMapper.readTree(cachingRequest.getContentAsByteArray())));
sb.append(String.format("====> Request: %s %s (%dms)\n====> Headers = %s\n",
request.getMethod(),
request.getRequestURL(),
endAt - startAt,
getHeaders(request)));
sb.append("====> Content-Type: ").append(request.getContentType()).append("\n");

if ("POST".equalsIgnoreCase(request.getMethod()) && cachingRequest.getContentAsByteArray().length > 0) {
try {
sb.append(String.format("====> Body: %s\n", objectMapper.readTree(cachingRequest.getContentAsByteArray())));
} catch (Exception e) {
sb.append("====> Body: [Unable to parse JSON]\n");
}
}

if (returnValue != null) {
sb.append(String.format("====> Response: {%s}\n", returnValue));
sb.append(String.format("====> Response: %s\n", returnValue));
}

if (exception != null) {
sb.append(String.format("====> Exception: %s\n", exception.getClass().getSimpleName()));
sb.append(String.format("====> Error Message: %s\n", exception.getMessage()));

StackTraceElement[] stackTrace = exception.getStackTrace();
if (stackTrace.length > 0) {
sb.append("====> Stack Trace (top 5):\n");
int limit = Math.min(5, stackTrace.length);
for (int i = 0; i < limit; i++) {
sb.append(String.format(" at %s\n", stackTrace[i].toString()));
}
}
}

sb.append(END_LOG);
return sb.toString();
}

private Map<String, Object> getHeaders(HttpServletRequest request) {
Map<String, Object> headerMap = new HashMap<>();

Enumeration<String> headerArray = request.getHeaderNames();
while (headerArray.hasMoreElements()) {
String headerName = headerArray.nextElement();
headerMap.put(headerName, request.getHeader(headerName));
}
return headerMap;
}
}

private void recordMetrics(HttpServletRequest request, long startAt, long endAt, String status) {
String method = request.getMethod();
String uri = getSimplifiedUri(request.getRequestURI());

Counter.builder("http_requests_total")
.description("Total HTTP requests")
.tag("method", method)
.tag("uri", uri)
.tag("status", status)
.register(meterRegistry)
.increment();

Timer.builder("http_request_duration_seconds")
.description("HTTP request duration in seconds")
.tag("method", method)
.tag("uri", uri)
.tag("status", status)
.register(meterRegistry)
.record(endAt - startAt, java.util.concurrent.TimeUnit.MILLISECONDS);
}

private String getSimplifiedUri(String requestUri) {
return requestUri.replaceAll("/\\d+", "/{id}")
.replaceAll("/[a-fA-F0-9]{8}-[a-fA-F0-9]{4}-[a-fA-F0-9]{4}-[a-fA-F0-9]{4}-[a-fA-F0-9]{12}", "/{uuid}");
}

private boolean isProdProfile() {
String[] activeProfiles = environment.getActiveProfiles();
for (String profile : activeProfiles) {
if ("prod".equals(profile)) {
return true;
}
}
return false;
}
}
2 changes: 1 addition & 1 deletion src/main/resources/config
12 changes: 11 additions & 1 deletion src/main/resources/file-error-appender.xml
Original file line number Diff line number Diff line change
@@ -1,14 +1,24 @@
<included>
<appender name="FILE-ERROR" class="ch.qos.logback.core.FileAppender">
<appender name="FILE-ERROR" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>/app/logs/error/error-${BY_DATE}.log</file>
<append>true</append>

<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>ERROR</level>
<onMatch>ACCEPT</onMatch>
<onMismatch>DENY</onMismatch>
</filter>

<encoder>
<pattern>${LOG_PATTERN}</pattern>
</encoder>

<rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
<fileNamePattern>/app/logs/error/error-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
<maxFileSize>100MB</maxFileSize>
<maxHistory>30</maxHistory>
<totalSizeCap>3GB</totalSizeCap>
<cleanHistoryOnStart>true</cleanHistoryOnStart>
</rollingPolicy>
</appender>
</included>
12 changes: 11 additions & 1 deletion src/main/resources/file-info-appender.xml
Original file line number Diff line number Diff line change
@@ -1,14 +1,24 @@
<included>
<appender name="FILE-INFO" class="ch.qos.logback.core.FileAppender">
<appender name="FILE-INFO" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>/app/logs/info/info-${BY_DATE}.log</file>
<append>true</append>

<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>INFO</level>
<onMatch>ACCEPT</onMatch>
<onMismatch>DENY</onMismatch>
</filter>

<encoder>
<pattern>${LOG_PATTERN}</pattern>
</encoder>

<rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
<fileNamePattern>/app/logs/info/info-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
<maxFileSize>100MB</maxFileSize>
<maxHistory>30</maxHistory>
<totalSizeCap>3GB</totalSizeCap>
<cleanHistoryOnStart>true</cleanHistoryOnStart>
</rollingPolicy>
</appender>
</included>
5 changes: 0 additions & 5 deletions src/main/resources/logback-spring.xml
Original file line number Diff line number Diff line change
Expand Up @@ -3,9 +3,6 @@
<property name="LOG_PATTERN"
value="[%d{yyyy-MM-dd'T'HH:mm:ss}:%-4relative] %green([%thread]) %highlight(%-5level) %boldWhite([%C.%M:%yellow(%L)]) - %msg%n"/>

<springProperty name="SLACK_DEV_WEBHOOK_URI" source="logging.slack.dev.webhook-uri"/>
<springProperty name="SLACK_PROD_WEBHOOK_URI" source="logging.slack.prod.webhook-uri"/>

<springProfile name="local">
<include resource="console-appender.xml"/>
<root level="INFO">
Expand All @@ -16,12 +13,10 @@
<springProfile name="dev">
<include resource="file-info-appender.xml"/>
<include resource="file-error-appender.xml"/>
<include resource="slack-dev-appender.xml"/>

<root level="INFO">
<appender-ref ref="FILE-INFO"/>
<appender-ref ref="FILE-ERROR"/>
<appender-ref ref="ASYNC_SLACK_DEV"/>
</root>
</springProfile>

Expand Down
29 changes: 0 additions & 29 deletions src/main/resources/slack-dev-appender.xml

This file was deleted.

6 changes: 3 additions & 3 deletions src/main/resources/slack-prod-appender.xml
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
<included>
<appender name="SLACK_PROD" class="com.github.maricn.logback.SlackAppender">
<webhookUri>${SLACK_PROD_WEBHOOK_URI}</webhookUri>
<webhookUri>https://hooks.slack.com/services/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</webhookUri>
<channel>#be-prod-log</channel>
<username>doldol-prod</username>
<iconEmoji>:rotating_light:</iconEmoji>
Expand All @@ -17,7 +17,7 @@
<appender-ref ref="SLACK_PROD"/>
<filter class="ch.qos.logback.core.filter.EvaluatorFilter">
<evaluator>
<expression>level == INFO || level == ERROR</expression>
<expression>level == ERROR</expression>
</evaluator>
<onMatch>ACCEPT</onMatch>
<onMismatch>DENY</onMismatch>
Expand All @@ -26,4 +26,4 @@
<queueSize>256</queueSize>
<includeCallerData>false</includeCallerData>
</appender>
</included>
</included>
Loading