요청 추적 로그 관련

[apptie]

배경

• 다양한 환경에서의 문제 발생
  • 해당 요청이 정상적으로 왔는지(ec2, nginx, 클라이언트 등등의 문제로 애플리케이션까지 요청이 도달했는지) 확인할 필요가 있음
  • 어느 시점에서 예외(컨트롤러, 서비스, 레포지토리 등등)가 발생했는지 확인할 필요가 있음
  • 요청은 성공했지만, 응답 과정에서 문제(클라이언트에서 원하는 응답이 아닌 경우, 코드에는 문제가 없지만 서비스 로직으로 봤을 때 문제가 생기는 경우 등등)가 생겼는지 확인할 필요가 있음
• 이에 대한 로그의 필요성을 느낌
• Request 전후(컨트롤러 요청 / 응답)만으로는 부족할 것이라고 판단
• AOP를 활용해 컨트롤러 - 서비스 - 레포지토리의 요청 흐름을 모두 추적하고 그에 대한 정보를 로그로 남기는 방식으로 결정
  • 겸사겸사 실행 경과 시간도 추가함
  • 겸사겸사 그라파나에서도 잘 보이게 json 형식으로 변경

간단 사전정보

• 콩하나의 AOP 테코톡 추천
• Pointcut : 어디에 이 AOP를 적용할지
• Around : 이 메서드가 적용될 조건을 명시(Pointcut 사용)
• Advice : 횡단 관심사(Cross-cutting Concerns) / 코드에서는 로그를 찍는 것과 관련된 모든 로직
• ProceedingJoinPoint : 실행 시점에서의 메서드 정보
• MDC : 로깅 시스템에서 로그 이벤트에 대한 추가 정보를 제공하기 위한 기능 제공 / 로그 이벤트마다 지정된 별도의 컨텍스트 정보를 가지고 있으므로 다른 스레드에서의 MDC와 구분 가능(ThreadLocal과 유사) / Map 형태라 저장한 순서대로 로그로 출력되지는 않음(순서 보장 X)
• logstash-logback-encoder : ELK의 구성 요소 중 하나로 로그를 중앙 집중형으로 모니터링하기 위한 라이브러리 / Logstash는 json 형식으로만 데이터를 전달할 수 있으므로 json 포맷으로 변경할 수 있는 기능 제공

예시

로그인하지 않은 경우(회원가입 / 로그인 등등)

{
  "@timestamp" : "2023-09-29T02:16:48.814+09:00",
  "resultTime" : "NONE",
  "level" : "0",
  "userId" : "Unauthorized",
  "requestId" : "21189196-3dba-4c74-88f8-6cd0b9d098b5",
  "requestUrl" : "/auctions",
  "message" : "AuctionController.readAllByCondition()"
}
{
  "@timestamp" : "2023-09-29T02:16:48.822+09:00",
  "resultTime" : "NONE",
  "level" : "1",
  "userId" : "Unauthorized",
  "requestId" : "21189196-3dba-4c74-88f8-6cd0b9d098b5",
  "requestUrl" : "/auctions",
  "message" : "|-->AuctionService.readAllByCondition()"
}
{
  "@timestamp" : "2023-09-29T02:16:48.822+09:00",
  "resultTime" : "NONE",
  "level" : "2",
  "userId" : "Unauthorized",
  "requestId" : "21189196-3dba-4c74-88f8-6cd0b9d098b5",
  "requestUrl" : "/auctions",
  "message" : "|   |-->JpaAuctionRepository.findAuctionsAllByCondition()"
}
{
  "@timestamp" : "2023-09-29T02:16:48.823+09:00",
  "resultTime" : "NONE",
  "level" : "3",
  "userId" : "Unauthorized",
  "requestId" : "21189196-3dba-4c74-88f8-6cd0b9d098b5",
  "requestUrl" : "/auctions",
  "message" : "|   |   |-->QuerydslAuctionRepositoryImpl.findAuctionsAllByCondition()"
}
{
  "@timestamp" : "2023-09-29T02:16:48.832+09:00",
  "resultTime" : "9ms",
  "level" : "3",
  "userId" : "Unauthorized",
  "requestId" : "21189196-3dba-4c74-88f8-6cd0b9d098b5",
  "requestUrl" : "/auctions",
  "message" : "|   |   |<--QuerydslAuctionRepositoryImpl.findAuctionsAllByCondition()"
}
{
  "@timestamp" : "2023-09-29T02:16:48.833+09:00",
  "resultTime" : "11ms",
  "level" : "2",
  "userId" : "Unauthorized",
  "requestId" : "21189196-3dba-4c74-88f8-6cd0b9d098b5",
  "requestUrl" : "/auctions",
  "message" : "|   |<--JpaAuctionRepository.findAuctionsAllByCondition()"
}
{
  "@timestamp" : "2023-09-29T02:16:48.833+09:00",
  "resultTime" : "12ms",
  "level" : "1",
  "userId" : "Unauthorized",
  "requestId" : "21189196-3dba-4c74-88f8-6cd0b9d098b5",
  "requestUrl" : "/auctions",
  "message" : "|<--AuctionService.readAllByCondition()"
}
{
  "@timestamp" : "2023-09-29T02:16:48.834+09:00",
  "resultTime" : "20ms",
  "level" : "0",
  "userId" : "Unauthorized",
  "requestId" : "21189196-3dba-4c74-88f8-6cd0b9d098b5",
  "requestUrl" : "/auctions",
  "message" : "AuctionController.readAllByCondition()"
}

로그인한 경우

{
  "@timestamp" : "2023-09-29T02:14:45.830+09:00",
  "resultTime" : "NONE",
  "level" : "0",
  "userId" : "1",
  "requestId" : "d8fefd06-b849-417f-a00a-0c5a579cbdf1",
  "requestUrl" : "/auctions",
  "message" : "BlackListTokenService.existsBlackListToken()"
}
{
  "@timestamp" : "2023-09-29T02:14:45.830+09:00",
  "resultTime" : "NONE",
  "level" : "1",
  "userId" : "1",
  "requestId" : "d8fefd06-b849-417f-a00a-0c5a579cbdf1",
  "requestUrl" : "/auctions",
  "message" : "|-->JpaBlackListTokenRepository.existsByTokenTypeAndToken()"
}
{
  "@timestamp" : "2023-09-29T02:14:45.833+09:00",
  "resultTime" : "3ms",
  "level" : "1",
  "userId" : "1",
  "requestId" : "d8fefd06-b849-417f-a00a-0c5a579cbdf1",
  "requestUrl" : "/auctions",
  "message" : "|<--JpaBlackListTokenRepository.existsByTokenTypeAndToken()"
}
{
  "@timestamp" : "2023-09-29T02:14:45.833+09:00",
  "resultTime" : "3ms",
  "level" : "0",
  "userId" : "1",
  "requestId" : "d8fefd06-b849-417f-a00a-0c5a579cbdf1",
  "requestUrl" : "/auctions",
  "message" : "BlackListTokenService.existsBlackListToken()"
}
{
  "@timestamp" : "2023-09-29T02:14:45.838+09:00",
  "resultTime" : "NONE",
  "level" : "0",
  "userId" : "1",
  "requestId" : "d8fefd06-b849-417f-a00a-0c5a579cbdf1",
  "requestUrl" : "/auctions",
  "message" : "AuthenticationUserService.isWithdrawal()"
}
{
  "@timestamp" : "2023-09-29T02:14:45.838+09:00",
  "resultTime" : "NONE",
  "level" : "1",
  "userId" : "1",
  "requestId" : "d8fefd06-b849-417f-a00a-0c5a579cbdf1",
  "requestUrl" : "/auctions",
  "message" : "|-->JpaUserRepository.existsByIdAndDeletedIsTrue()"
}
{
  "@timestamp" : "2023-09-29T02:14:45.840+09:00",
  "resultTime" : "2ms",
  "level" : "1",
  "userId" : "1",
  "requestId" : "d8fefd06-b849-417f-a00a-0c5a579cbdf1",
  "requestUrl" : "/auctions",
  "message" : "|<--JpaUserRepository.existsByIdAndDeletedIsTrue()"
}
{
  "@timestamp" : "2023-09-29T02:14:45.841+09:00",
  "resultTime" : "3ms",
  "level" : "0",
  "userId" : "1",
  "requestId" : "d8fefd06-b849-417f-a00a-0c5a579cbdf1",
  "requestUrl" : "/auctions",
  "message" : "AuthenticationUserService.isWithdrawal()"
}
{
  "@timestamp" : "2023-09-29T02:14:45.841+09:00",
  "resultTime" : "NONE",
  "level" : "0",
  "userId" : "1",
  "requestId" : "d8fefd06-b849-417f-a00a-0c5a579cbdf1",
  "requestUrl" : "/auctions",
  "message" : "AuctionController.readAllByCondition()"
}
{
  "@timestamp" : "2023-09-29T02:14:45.842+09:00",
  "resultTime" : "NONE",
  "level" : "1",
  "userId" : "1",
  "requestId" : "d8fefd06-b849-417f-a00a-0c5a579cbdf1",
  "requestUrl" : "/auctions",
  "message" : "|-->AuctionService.readAllByCondition()"
}
{
  "@timestamp" : "2023-09-29T02:14:45.842+09:00",
  "resultTime" : "NONE",
  "level" : "2",
  "userId" : "1",
  "requestId" : "d8fefd06-b849-417f-a00a-0c5a579cbdf1",
  "requestUrl" : "/auctions",
  "message" : "|   |-->JpaAuctionRepository.findAuctionsAllByCondition()"
}
{
  "@timestamp" : "2023-09-29T02:14:45.842+09:00",
  "resultTime" : "NONE",
  "level" : "3",
  "userId" : "1",
  "requestId" : "d8fefd06-b849-417f-a00a-0c5a579cbdf1",
  "requestUrl" : "/auctions",
  "message" : "|   |   |-->QuerydslAuctionRepositoryImpl.findAuctionsAllByCondition()"
}
{
  "@timestamp" : "2023-09-29T02:14:45.845+09:00",
  "resultTime" : "3ms",
  "level" : "3",
  "userId" : "1",
  "requestId" : "d8fefd06-b849-417f-a00a-0c5a579cbdf1",
  "requestUrl" : "/auctions",
  "message" : "|   |   |<--QuerydslAuctionRepositoryImpl.findAuctionsAllByCondition()"
}
{
  "@timestamp" : "2023-09-29T02:14:45.846+09:00",
  "resultTime" : "4ms",
  "level" : "2",
  "userId" : "1",
  "requestId" : "d8fefd06-b849-417f-a00a-0c5a579cbdf1",
  "requestUrl" : "/auctions",
  "message" : "|   |<--JpaAuctionRepository.findAuctionsAllByCondition()"
}
{
  "@timestamp" : "2023-09-29T02:14:45.846+09:00",
  "resultTime" : "4ms",
  "level" : "1",
  "userId" : "1",
  "requestId" : "d8fefd06-b849-417f-a00a-0c5a579cbdf1",
  "requestUrl" : "/auctions",
  "message" : "|<--AuctionService.readAllByCondition()"
}
{
  "@timestamp" : "2023-09-29T02:14:45.846+09:00",
  "resultTime" : "5ms",
  "level" : "0",
  "userId" : "1",
  "requestId" : "d8fefd06-b849-417f-a00a-0c5a579cbdf1",
  "requestUrl" : "/auctions",
  "message" : "AuctionController.readAllByCondition()"
}

예외 발생 시

{
  "@timestamp" : "2023-09-29T02:26:02.818+09:00",
  "resultTime" : "NONE",
  "level" : "0",
  "userId" : "Unauthorized",
  "requestId" : "8b8d548b-1551-4fad-b2c7-62f9b07dc56a",
  "requestUrl" : "/auctions/50",
  "message" : "AuctionController.read()"
}
{
  "@timestamp" : "2023-09-29T02:26:02.826+09:00",
  "resultTime" : "NONE",
  "level" : "1",
  "userId" : "Unauthorized",
  "requestId" : "8b8d548b-1551-4fad-b2c7-62f9b07dc56a",
  "requestUrl" : "/auctions/50",
  "message" : "|-->AuctionService.readByAuctionId()"
}
{
  "@timestamp" : "2023-09-29T02:26:02.829+09:00",
  "resultTime" : "NONE",
  "level" : "2",
  "userId" : "Unauthorized",
  "requestId" : "8b8d548b-1551-4fad-b2c7-62f9b07dc56a",
  "requestUrl" : "/auctions/50",
  "message" : "|   |-->JpaAuctionRepository.findAuctionById()"
}
{
  "@timestamp" : "2023-09-29T02:26:02.830+09:00",
  "resultTime" : "NONE",
  "level" : "3",
  "userId" : "Unauthorized",
  "requestId" : "8b8d548b-1551-4fad-b2c7-62f9b07dc56a",
  "requestUrl" : "/auctions/50",
  "message" : "|   |   |-->QuerydslAuctionRepositoryImpl.findAuctionById()"
}
{
  "@timestamp" : "2023-09-29T02:26:02.847+09:00",
  "resultTime" : "17ms",
  "level" : "3",
  "userId" : "Unauthorized",
  "requestId" : "8b8d548b-1551-4fad-b2c7-62f9b07dc56a",
  "requestUrl" : "/auctions/50",
  "message" : "|   |   |<--QuerydslAuctionRepositoryImpl.findAuctionById()"
}
{
  "@timestamp" : "2023-09-29T02:26:02.848+09:00",
  "resultTime" : "19ms",
  "level" : "2",
  "userId" : "Unauthorized",
  "requestId" : "8b8d548b-1551-4fad-b2c7-62f9b07dc56a",
  "requestUrl" : "/auctions/50",
  "message" : "|   |<--JpaAuctionRepository.findAuctionById()"
}
{
  "@timestamp" : "2023-09-29T02:26:02.849+09:00",
  "resultTime" : "23ms",
  "level" : "1",
  "userId" : "Unauthorized",
  "requestId" : "8b8d548b-1551-4fad-b2c7-62f9b07dc56a",
  "requestUrl" : "/auctions/50",
  "message" : "|<X-AuctionService.readByAuctionId()"
}
{
  "@timestamp" : "2023-09-29T02:26:02.853+09:00",
  "resultTime" : "35ms",
  "exception" : "AuctionNotFoundException",
  "level" : "0",
  "requestId" : "8b8d548b-1551-4fad-b2c7-62f9b07dc56a",
  "requestUrl" : "/auctions/50",
  "userId" : "Unauthorized",
  "exceptionMessage" : "지정한 아이디에 대한 경매를 찾을 수 없습니다.",
  "message" : "AuctionController.read()"
}