분류 전체보기 (356)

💻 Programming

Spock Test Framework 실행 오류 해결

(SpringBoot3 + Correto 17 (java 17) 환경에서 spock test 시 발생한

TestEngine with ID 'spock' failed to discover tests 오류 해결방안 공유합니다.

 

IntelliJ 에서 Spring Initializer를 이용하여

스프링부트3 + 자바 17 기반의 신규 프로젝트를 생성,

빌드가 정상적으로 되는지 확인 후

spock 테스트를 위한 라이브러리를 아래 3개 추가했습니다.

testImplementation 'org.spockframework:spock-core:2.4-M1-groovy-4.0'
testImplementation 'org.spockframework:spock-spring:2.4-M1-groovy-4.0'
testImplementation 'org.apache.groovy:groovy-all:4.0.13'

 

 

그리고 샘플 테스트 클래스를 만들었습니다.

class SampleSpec extends Specification {

    def "where with variables: #size"() {
        when:
        def list = new ArrayList(size)

        then:
        list.size() == 0

        where:
        size << [1, 2, 3, 4, 5]
    }

    def "using data tables for calculating max, Max of #a and #b is #max"() {
        expect:
        Math.max(a, b) == max

        where:
        a | b || max
        1 | 2 || 2
        7 | 4 || 7
        0 | 0 || 0
    }
}

 

 

실행을 해보았더니 아래와 같은 에러가 발생했습니다.

Internal Error occurred.
org.junit.platform.commons.JUnitException: TestEngine with ID 'spock' failed to discover tests
...중략...

Caused by: org.junit.platform.commons.JUnitException: ClassSelector [className = 'com.project.SampleSpec', classLoader = null] resolution failed
...중략...

Caused by: org.junit.platform.commons.PreconditionViolationException: Could not load class with name: com.project.SampleSpec
...중략...

Caused by: java.lang.ClassNotFoundException: com.project.SampleSpec

 

 

구글링 결과 build.gradle 파일의 plugins 에 id 'groovy' 를 추가해주면 되는 문제였습니다.

plugins {
    id 'java'
    id 'org.springframework.boot' version '3.2.1'
    id 'io.spring.dependency-management' version '1.1.4'

    id 'groovy'  <-- 이게 있는지 확인
}

 

최근 2년정도 IntelliJ에서 Java 11 기반의 AWS Correto 11 을 사용해왔습니다

그래서 현재 JAVA_HOME 은 AWS Correto 11 의 위치를 가리키고 있었습니다.

신규 프로젝트 구성할 일이 생겼고

AWS Correto 17 을 미리 다운받아둔 상태에서

IntelliJ 에서 SpringBoot Initializer 를 이용해서

아래와 같은 설정(Java 17 + gradle groovy)으로 프로젝트를 생성하고

빌드를 하니 오류가 발생했습니다.

스프링부트 신규 프로젝트 생성 설정화면 (Java 17 설정)

 

아래는 빌드시 발생했던 오류 메시지

A problem occurred configuring root project 'my-new-springboot3-project'.
> Could not resolve all files for configuration ':classpath'.
   > Could not resolve org.springframework.boot:spring-boot-gradle-plugin:3.2.1.
     Required by:
         project : > org.springframework.boot:org.springframework.boot.gradle.plugin:3.2.1
      > No matching variant of org.springframework.boot:spring-boot-gradle-plugin:3.2.1 was found. The consumer was configured to find a library for use during runtime, compatible with Java 11, packaged as a jar, and its dependencies declared externally, as well as attribute 'org.gradle.plugin.api-version' with value '8.5' but:
          - Variant 'apiElements' capability org.springframework.boot:spring-boot-gradle-plugin:3.2.1 declares a library, packaged as a jar, and its dependencies declared externally:
              - Incompatible because this component declares a component for use during compile-time, compatible with Java 17 and the consumer needed a component for use during runtime, compatible with Java 11
              - Other compatible attribute:
                  - Doesn't say anything about org.gradle.plugin.api-version (required '8.5')
          - Variant 'javadocElements' capability org.springframework.boot:spring-boot-gradle-plugin:3.2.1 declares a component for use during runtime, and its dependencies declared externally:
              - Incompatible because this component declares documentation and the consumer needed a library
              - Other compatible attributes:
                  - Doesn't say anything about its target Java version (required compatibility with Java 11)
                  - Doesn't say anything about its elements (required them packaged as a jar)
                  - Doesn't say anything about org.gradle.plugin.api-version (required '8.5')
          - Variant 'mavenOptionalApiElements' capability org.springframework.boot:spring-boot-gradle-plugin-maven-optional:3.2.1 declares a library, packaged as a jar, and its dependencies declared externally:
              - Incompatible because this component declares a component for use during compile-time, compatible with Java 17 and the consumer needed a component for use during runtime, compatible with Java 11
              - Other compatible attribute:
                  - Doesn't say anything about org.gradle.plugin.api-version (required '8.5')
          - Variant 'mavenOptionalRuntimeElements' capability org.springframework.boot:spring-boot-gradle-plugin-maven-optional:3.2.1 declares a library for use during runtime, packaged as a jar, and its dependencies declared externally:
              - Incompatible because this component declares a component, compatible with Java 17 and the consumer needed a component, compatible with Java 11
              - Other compatible attribute:
                  - Doesn't say anything about org.gradle.plugin.api-version (required '8.5')
          - Variant 'runtimeElements' capability org.springframework.boot:spring-boot-gradle-plugin:3.2.1 declares a library for use during runtime, packaged as a jar, and its dependencies declared externally:
              - Incompatible because this component declares a component, compatible with Java 17 and the consumer needed a component, compatible with Java 11
              - Other compatible attribute:
                  - Doesn't say anything about org.gradle.plugin.api-version (required '8.5')
          - Variant 'sourcesElements' capability org.springframework.boot:spring-boot-gradle-plugin:3.2.1 declares a component for use during runtime, and its dependencies declared externally:
              - Incompatible because this component declares documentation and the consumer needed a library
              - Other compatible attributes:
                  - Doesn't say anything about its target Java version (required compatibility with Java 11)
                  - Doesn't say anything about its elements (required them packaged as a jar)
                  - Doesn't say anything about org.gradle.plugin.api-version (required '8.5')

* Try:
> Run with --stacktrace option to get the stack trace.
> Run with --info or --debug option to get more log output.
> Run with --scan to get full insights.
> Get more help at https://help.gradle.org.
BUILD FAILED in 1s

 

에러 메시지의 내용을 읽어보니, 일단 Could not resolve xxx 의 경우 xxx 라이브러리가 없다라는 메시지인데

신규 생성한 프로젝트에서 필수라이브러리를 dependency에 안넣을 이유가 없다는 생각이 우선 들었습니다.

그런거라면 springboot initializer 의 버그일테니까요.

그래서 더 읽어봤습니다.

그리고 "requierd compatibility with Java 11" 문구가 눈에 띄었습니다.

난 자바17을 쓰려고 17버전으로 JDK와 Java 설정을 넣었는데 왜 Java 11 관련메시지가 뜨는건지 이상했습니다. 🤔

에러메시지 내용으로 구글링을 좀 해보니 아래 부분들을 확인해보라는 내용들이 있었습니다.

  • 현재 시스템에서 사용하는 Java 버전 확인 (java -version)
  • build.gradle 파일의  sourceCompatibility 확인
  • IntelliJ 의 project SDK 설정 확인
  • gradle JVM 설정 확인

일단 빌드시에 발생했고, 빌드툴은 gradle 이라는 걸 이미 프로젝트 생성시 설정을 해주었고, IntelliJ에 gradle 이 사용할 자바버전을 설정하는 내용이 있다는 것을 알고있었기에 gradle JVM 설정을 먼저 확인해봤습니다.

gradle JVM 설정이 기존 설정 그대로 Java 11을 사용하도록 되어있었습니다. 😭

프로젝트 생성시 correto 17, Java 17 버전을 설정해주었기에 sourceCompatibility 와 project SDK 는 17버전을 사용하도록 되어있었고, JAVA_HOME에 설정되어있는 현재 시스템에서 기본으로 사용중인 Java 버전과는 관계가 없었습니다.

 

gradle JVM 설정 확인 방법

Preferences/Settings (⌘ + , ) > Build, Execution, Deployment > Build Tools > Gradle

Gradle JVM 설정 화면

project SDK 설정 확인 방법

File > Project Structure.. (⌘ + ; )

Project SDK 설정 화면

build.gradle 파일의 sourceCompatibility 확인 방법

build.gradle 파일에서 sourceCompatibility 설정 방법

💻 Programming

SpringBoot 2.3 -> 2.5 업그레이드 후기

SpringBoot 버전을 업그레이드 해야할 일이 생겨서 2.3 버전을 2.5 버전으로 업그레이드한 경험담을 공유합니다.

개발인생 처음으로 해보는 레거시 시스템의 프레임워크 업그레이드 작업이었습니다.

대부분은 신규 프로젝트를 만들거나 deprecate 된 상태로 유지하는 정도였죠.

그래도 해보고 싶었던 부분이었습니다. 업무가 많이 지루해진것도 한 몫 했죠.

저는 주기적으로 반기에 한번정도는 라이브러리 업그레이드 작업을 진행해야한다고 생각하지만

저희 개발팀은 이상하게 라이브러리 업그레이드 작업을 안합니다. 

그런데 갑자기 프레임워크 업그레이드를 하려니 dependency 가 많이 걸려있을거라 예상했죠.

 

우선 2.3 -> 2.4 로 올라가면서 어떤 부분에 변화가 생겼는지를 확인하고 대응하고,

2.4 -> 2.5 에서는 어떤 변화가 있었는지 확인하여 대응하면 될거라 생각했고 

아래 2개의 spring boot release note 를 하나하나 살펴봤습니다.

2.3 -> 2.4 에서 변경된 부분

  • JUnit 5’s Vintage Engine Removed from spring-boot-starter-test
  • Config File Processing (application properties and YAML files)
  • Config Data Imports
  • Embedded database detection
  • User-defined MongoClientSettings no longer customized
  • Logback Configuration Properties
  • Default Servlet Registration
  • HTTP traces no longer include cookie headers by default
  • Undertow Path on Forward
  • Neo4j
  • Hazelcast 4
  • Elasticsearch RestClient
  • R2DBC
  • Flyway
  • Removal of Plugin Management for Flatten Maven Plugin
  • Version management for exec-maven-plugin
  • Spring Boot Gradle Plugin
  • Metrics export in integration tests
  • Deprecations from Spring Boot 2.2 and 2.3

2.4 -> 2.5 에서 변경된 부분

  • SQL Script DataSource Initialization
  • Flyway and Liquibase JDBC URLs
  • Spring Data JPA
  • Spring Data Solr
  • Secure Info Endpoint
  • Task Scheduling Harmonization with Spring Integration
  • Default Expression Language (EL) Implementation
  • Messages in the Default Error View
  • Logging Shutdown Hooks
  • Gradle Default jar and war Tasks
  • Cassandra Throttling Properties
  • Customizing jOOQ’s DefaultConfiguration
  • Groovy 3
  • Minimum Requirements Changes
  • Hibernate Validator 6.2

위에 나온 내용 이외에도 업그레이드 되면서 deprecated 되는 것들에 대한 부분들, 그리고 새로 추가 된 부분들에 대한 설명을 하나하나 읽어보고 현재 내가 담당하는 프로젝트에서 사용되는 것들과 연관된 것들을 모두 읽어보았습니다.

그리고 spring boot 버전을 변경한 뒤 오류가 발생하는 부분은 없는지 배포는 잘 되는지를 확인했습니다.

boot 업그레이드 작업하면서 변경했던 부분은 아래 내용들이었습니다.

  • spring.config.use-legacy-processing = true 설정을 추가
  • fasterxml.jackson.databind.PropertyNamingStrategy -> PropertyNamingStrategies 클래스 변경
  • third-party dependency 들 중에서 업그레이드가 필요한 것들 확인 및 업그레이드
  • gradle 버전 업그레이드 6.7 -> 6.9

작업 내용만보면 진짜 별거 아니었던 작업으로 보이네요. 작업시간보다 문서 읽어보는 시간이 더 오래 걸렸던것 같습니다. 링크를 타고타고 들어가야 확인할 수 있는 것들이 많다보니..

아무튼 로컬환경에서 잘 돌아가는 것까지 확인 하고 개발에 올려 테스트를 해보니 애플리케이션이 정상적으로 실행되지 못하는 현상이 확인되었습니다. 왜 그런가 봤더니 jar 파일명이 이상하게 바뀌어있었습니다. 끝에 -plain postfix가 붙은 파일명이 배포된 것을 확인했고 이게 뭔가 싶어 구글링을 해보니 release note 에서 설명을 찾아볼 수 없었지만(내가 못 본 걸수도?) 2.5버전부터 발생하는 현상이었고 gradle 설정에서 jar task를 비활성화 시키거나 배포파일을 만드는 task 에서 해당 파일을 exclude 처리하면 되는 문제였습니다.

 

매일 반복되는 특별하지 않은 업무들만 하다가 처음으로 해본 프레임워크 업그레이드 작업은 너무 재미있었고 좋은 경험이었습니다.

 

내년에는 java 17 + SpringBoot 3 기반의 신규 프로젝트를 하나 만들어야 하는데 벌써부터 기대되고 현재 사용중인 java 11 에서 17까지 어떤 변화들이 있었는지 확인하는 시간을 가져야 할 것 같습니다.

 

개인프로젝트를 하다보면 한동안 작업진행을 못하다가 다시 재개하는 경우가 많은데

이때 노트북을 새로 바꾸었거나, 프로젝트 디렉토리를 잘못해서 삭제했다가

다시 git clone 할 때 Invalid username or password 를 보게 된다.

github 에서 https 주소로 clone 을 하거나

토근유효기간을 넘겨서 git push를 하게되면

invalid 오류가 발생하게 된다.

1년에도 여러번 이런 일이 발생하는데

어떻게 처리해야하는지 자꾸 까먹어서 기록용으로 남깁니다.

Github 계정의 Settings > Developer Settings 로 가서

Personal Access Token(이하 PAT) 을 재생성(regenerate)합니다.

그리고 git clone 의 경우 아래처럼 clone 명령을 입력합니다.

https://계정명:PAT@github.com/클론할_repo의 주소

git push 의 경우 username과  password 를 입력하는 프롬프트가 뜨게되는데

이때 password 에 github 웹 로그인시 입력하는 password 가 아닌 PAT 를 입력하면됩니다. 

포스팅을 너무 오랜만에 하네요.

요즘은 회사사정도 별로고 회사업무에서 배우는 것도 뭐 없다보니 블로그에 글을 잘 안쓰게 되네요.

하지만!!!! 성장에 대한 욕구는 아직도 초심과 같다는... ㅎㅎ

flutter 에 매료된 올해 초부터 flame 을 이용하여 게임개발을 진행했었습니다.

1일차 이후로 포스팅을 하지 않았지만

flutter와 flame 공식문서 읽어가면서 짬짬이 개발을 진행했고

5월 31일 구글플레이에 출시됐습니다.

대략 주 2회 밤샘 작업으로 진행을 했으니 실제 개발기간은 2개월정도 될 것 같네요

일단 결과물이 어떻게 나왔는지 보고 싶으실 것 같아 구글플레이 링크를 하나 남깁니다

https://play.google.com/store/apps/details?id=com.keichee.exterminate_mosquitoes&hl=ko-KR

 

모기 헌터 - Google Play 앱

인류 최대의 해충! 모기를 박멸하고 지구를 구해주세요

play.google.com

 

모기를 잡으면서 여섯가지 종류의 모기들을 수집하고,

능력치를 향상시키면서 더 높은 stage 로 올라가고,

광고시청으로 레벨업에 필요한 코인(?)을 추가획득 할 수 있습니다.

리더보드도 추가해볼 예정입니다.

💻 Programming/Flutter & Dart & Flame

[Flame] 게임 개발 1일차

요즘 flutter & flame 으로 1인게임 개발을 진행하고 있는데 알아야 할게 너무나도 많아 문서 찾아보고 유툽 영상 찾아보면서 얕은 지식을 조금씩 조금씩 모으다가 지겨워져서 엊그제 하루 날 잡아서 퇴근하고 밤새워 구글링해가면서 만들어봤습니다.

인트로 화면도 로비화면도 없고 그냥 모기 날아다니게 만들고 터치하면 HP 줄어들면서 사라지고 단계별로 정해진 모기들을 모두 잡으면 다음 단계로 넘어가도록 했습니다. 아래는 샘플 영상입니다.

 

원래 단계별로 일정 마리수의 모기가 나오도록 해놓았으나 단계별로 모기마리수를 제외하면 특별할게 없어서 단계당 한마리씩만 출몰하도록 설정을 변경한 뒤 녹화했습니다. 단계별로 모기의 HP도 늘어납니다. ㅎㅎ

아직 해야할게 많이 있지만 중간중간 기록을 위해 포스팅합니다.

앞으로 해야할 것들은... HP바 만들기... 유저 로그인 및 최종게임상태 저장하기, 리더보드, 모기의 유저공격 기능, 유저 및 모기 공격력, 장비&스킬, 보스급모기, 보스출현시 애니메이션 등등 기획하기 및 그림그리기 등등... 너무 많이 있지만 천천히 끝까지 가보려고 합니다 ㅎ

 

flutter 에 입문한지 2주정도 되가는것 같네요

우연히 유툽통해서 접한뒤로 반해가지고 실제 업무에서 쓸일은 없을 것 같지만 모바일앱이든 웹이든 1인개발용으로 너무 좋을 것 같아 입문했습니다.

한 2주동안 책 구입해서 읽고, 공식문서 읽고, 책 예제와 코드랩 예제들 그리고 유툽 예제들 따라해보고나서,

간단한 타자연습 앱을 만들어 봤는데 어떤 위젯을 사용할지부터해서 처음부터 끝까지 오로지 제 생각만으로 하나 만들어보았습니다. (예제 따라하기는 코드랩이 제일 배우기 좋았던 것 같습니다)

타수계산할때 한글은 영어보다 까다로울 것 같아 영문버전으로만 만들었습니다.

이것저것 더 추가하고 싶은 기능(리더보드, 실시간 배틀)들도 있고 flame 을 이용해서 타자를 이용한 여러 게임모드들을 추가하는 등 좀더 게임스럽게 꾸며보고도 싶은데 일단 그냥 기록용도로 남겨봅니다.

매우 간단한 앱이지만 flutter와 더 친숙해질 수 있었던것 같아 매우 유익했던 시간이었네요.

모바일 앱 버전과 웹 버전을 분기태워서 조금 다르게 가져갈 수도 있었는데 아직은 웹보다는 앱개발에 더 최적화된 프레임워크인 것 같습니다.

이제 슬슬 flame 으로 넘어가보려 합니다 :)

자판 연습용 앱

 

아래 영상은 첫 날 설치해서 실행해본 데모앱의 내용을 다 지우고 처음부터 작성하면서 화면 이동, 각종 버튼 추가, 그리고 버튼에 이벤트 핸들링 기능을 넣어보는 기초적인 부분에 대해서 빠르게 가르쳐 주고있습니다. 처음 플러터를 접하는 분들에게 딱 좋은 영상인것 같아서 공유합니다.

 

https://www.youtube.com/watch?v=C-fKAzdTrLU 

 

그리고 플러터 공식문서에서도 Cookbook 에서 기본적으로 필요한 기능들에대해 어떻게 구현해야하는지 예제샘플들을 갖추고 있고, codelab 이라는 단계별 따라해보기와 같은 자료도 제공해주고 있습니다. 코드랩을 따라해보면 앱을 개발할때 어떻게 개발이 진행되는지 그 순서도 배울 수 있습니다.

구글에서 엄청나게 밀고있다는게 느껴질 정도로 기반자료들이 매우 많이 있네요.

플러터를 써보려다가 다트를 공부하기 시작..

Dart 가 어떤 언어인지에대한 간략한 소개내용을 공식문서에서 읽어봤습니다.

얼핏 보니 자바와 매우 유사합니다.

객체지향 언어이고 변수, loop, 메서드, 클래스 등등 매우 많은 부분에서 유사한 점을 보이고 있음.

자바와 다트의 차이점을 나열해보자면..다트는 아래와 같은 특징 또는 기능이 있습니다.

  • primitive(원시) 타입이 없음. 자바의 경우 int, long, double 과 같은 원시타입과 이 원시타입들의 wrapper 클래스인 Integer, Long, Double 등이 존재하지만, 다트는 모든 타입이 Object 임.
  • 변수 사용법 (출력시 문자열을 "이걸 출력할건데 변수명을 붙였어요 $변수명" 이렇게 써주면 $변수명 이 변수가 들고있는 값으로 치환되어 출력됨. 자바의 경우 String.format 을 이용해야 했음), 변수명 자리에 {expression} 을 사용하여 계산식을 사용할 수도 있음
  • null safety (Dart 2.12 버전부터 생김. 자바의 NPE 예방을 개발자가 아닌 컴파일러가 해주도록 한 기능으로 기본적으로 모든 객체는 non-nullable 로 취급함. 다만 ? 기호를 이용해서 nullable 객체라고 명시적으로 선언하면 null 값도 사용할 수 있음, 공식문서 참고)
  • private, protected, public, default 같은 접근제한자(access modifier)가 없음. 다만 이름이 밑줄로 시작하면 해당 라이브러리(클래스?)에 private한 것이 됨.
  • 다트의 int 타입은 64 비트 signed 값이고 플랫폼에 따라 범위가 약간 다름 (공식문서)

뭐 이외에도 lexical scope, lexical closure 등 여러 부분에서 다른 부분들이 보였는데 여기 다 나열할 수는 없고,

전체적인 느낌은 자바와 자바스크립트를 합쳐놓은 언어라는 느낌을 받았습니다. (해본게 Java랑 Javascript 뿐이라.. ㅎ)

 

참고로 다트패드에서 이런저런 다트코드들을 시험해볼 수 있습니다.

우연히 어떤 1인 개발자의 이야기를 유툽에서 접하고 나도 1인 개발이나 해야겠다 생각하던 찰나 또 우연히 플러터 강사의 영상을 본 뒤 목표를 달성하기 위한 매우 매력적인 프레임워크라는 생각이 들어서 플러터에 대해서 알아보려고 합니다. 

 

우선 공식 사이트에서 플러터가 뭔지부터 확인을 좀 해봤는데요

플러터는 구글에서 만든 크로스플랫폼 UI 프레임워크입니다.

모바일(안드 , IOS 둘다), 데스크탑 앱(Windows .exe 파일, MacOS .dmg파일), 웹 까지 모두 하나의 소스코드로 배포가 가능하죠.

이런게 바로 슈퍼앱이 아닌가 싶네요. 여기까지하고 일단 무작정 따라해봅니다.

 

아래 링크의 설명대로 명령어를 실행한다.

https://docs.flutter.dev/get-started/install/macos

 

macOS install

How to install on macOS.

docs.flutter.dev

 

1.  sudo softwareupdate --install-rosetta --agree-to-license

Password:
By using the agreetolicense option, you are agreeing that you have run this tool with the license only option and have read and agreed to the terms.
If you do not agree, press CTRL-C and cancel this process immediately.
2023-01-18 17:11:11.031 softwareupdate[62998:409413] Package Authoring Error: 012-92132: Package reference com.apple.pkg.RosettaUpdateAuto is missing installKBytes attribute
Install of Rosetta 2 finished successfully

뭔가 에러가 났는데 성공적으로 설치했다고 나오네요 !?

 

2. flutter docter 

아래처럼 이쁘게도 분석 결과를 보여주는군요

일단 X표시가 뜬 것들을 설치해야겠어요..

 

  • 안드로이드 스튜디오 설치 및 최초실행하여 sdk 다운로드, 라이센트 동의, cli tool 설치 등 완료
  • Xcode 설치 완료 및 라이센스 관련 오류 해결

 

현재 CocoaPods 이슈와 안드로이드 스튜디오에서 번들자바가 없다는 warning만 남기고 해결.

 

VS Code 를 IDE로 선택해서 테스트앱 생성, 실행 및 수정하여 hot reload 까지 확인완료.

 

다음엔 https://docs.flutter.dev/get-started/codelab 여기부터 진행 예정.

 

이었으나... 버전이 다른건지 신규 프로젝트 생성시 샘플 예제가 달라서 일단 dart 언어에 대해 알아보기로 함...

얼핏 봤을 때는 자바와 매우 비슷함..

💻 Programming

[AWS/SQS] cloudwatch datapoint 조회하기

안녕하세요, 이번엔 이벤트드리븐 서비스의 개선작업을 하다가 알게된 cloudwatch 통계지표 조회방법을 공유드립니다.

이 작업을 하게된 이유를 말씀드리자면 이렇습니다.

현재 SQS 를 이용한 이벤트드리븐 환경에서 동작하는 서비스가 있습니다. 

이런 저런 정보들을 동기화하기 위한 목적으로 사용하고 있고, 이 서비스는 멀티쓰레드 환경에서 동작하도록 되어있습니다.

혹시라도 이벤트가 지연될 경우를 대비해서 쓰레드 개수를 수시로 수동조절할 수 있도록 구성해두었죠.

그리고 지연이 발생하여 SQS 메시지가 발행된 뒤 일정 시간동안 처리를 못하여 큐에 계속 남아있게되면 alert가 발생하도록 되어있습니다.

즉, SQS의 ApproximateAgeOfOldestMessage 지표값을보고 너무 오래동안 처리가 안될 경우 alert를 받고 수동으로 쓰레드 개수를 조절하는 형태로 위기를 벗어나고 있습니다. 그런데 이 드물디 드문 사건이라도 개발자라면, 그리고 가능한 케이스라면 그냥 전부 다 자동화를 해놓아야 하지 않을까 생각이 들어 개선 작업에 들어갔습니다.

 

일단 SQS에서 제공하는 모니터링 지표는 아래와 같습니다. (AWS 콘솔화면의 모니터링 탭에서 볼 수 있는 것들입니다)

  • Approximate Number Of Messages Delayed
  • Approximate Number Of Messages Not Visible
  • Approximate Number Of Messages Visible
  • Approximate Age Of Oldest Message
  • Number Of Empty Receives
  • Number Of Messages Deleted
  • Number Of Messages Received
  • Number Of Messages Sent
  • Sent Message Size

이 지표에 해당하는 통계수치는 cloudwatch 에서 수집이 됩니다.

클라우드워치에서 수집된 데이터를 가지고 모니터링탭에 그래프로 보여주는 것이죠.

 

이제 제가 원하는 Approximate Age Of Oldest Message 에 대한 데이터를 뽑아보도록 하겠습니다.

일단 앱의 구성은 다음과 같습니다.

  • SpringBoot 2.3.x
  • AWS Java SDK 1.11.x
  • Java 11

AWS java sdk 에서는 cloudwatch 서비스에서 제공하는 API를 호출하여 클라우드워치 데이터를 조회할 수 있도록 cloudwatch client를 제공합니다. 제일 먼저 이 클라이언트를 빈으로 등록합니다.

@Configuration
public class AWSConfig {

    private AWSCredentialsProvider awsCredentialsProvider() {
        List<AWSCredentialsProvider> credentialsProviders = new ArrayList<>();
        credentialsProviders.add(new InstanceProfileCredentialsProvider(true));
        credentialsProviders.add(new ProfileCredentialsProvider());
        return new AWSCredentialsProviderChain(credentialsProviders);
    }

    @Bean
    public AmazonCloudWatch cloudWatchClient() {
        return AmazonCloudWatchClientBuilder.standard()
                .withCredentials(awsCredentialsProvider())
                .withRegion(Regions.fromName("ap-northeast-2"))
                .build()
                ;
    }
}

 

그리고 서비스 레이어에서 이 cloudWatchClient를 가져다 써보겠습니다.

    private void getQueueStatus(String queueName) {
        long currentMillis = System.currentTimeMillis();
        long fiveMinutesInMillis = 5 * 60 * 1000;
        GetMetricStatisticsRequest statisticsRequest = new GetMetricStatisticsRequest()
                .withNamespace("AWS/SQS").withMetricName("ApproximateAgeOfOldestMessage")
                .withStatistics(Statistic.Maximum).withPeriod(300)
                .withStartTime(new Date(currentMillis - fiveMinutesInMillis))
                .withEndTime(new Date(currentMillis))
                .withDimensions(new Dimension().withName("QueueName").withValue(queueName));

        GetMetricStatisticsResult result = cloudWatch.getMetricStatistics(statisticsRequest);
        log.debug("dataPoints: {}", result.getDatapoints());
    }

 

cloudWatchClient 를 이용하여 통계수치 데이터를 조회하려면 GetMetricStatisticsRequest 객체를 만들어서 넣어주어야 합니다. 

이 객체에 설정해줘야 하는 값들 중 필수적인 것들만 설정해보았습니다. 

간략히 설명하자면 다음과 같습니다.

  • withNameSpace: cloudwatch에서 서비스를 구분하는 값 (ex. "AWS/SQS", "AWS/EC2", etc.)
  • withMetricName: 조회하고자하는 메트릭 명
  • withStatistics: Statistic 에서 제공하는 통계기준(?), enum으로 정의되어있음
    • SampleCount
    • Average
    • Sum
    • Minimum
    • Maximum
  • withStartTime, withEndTime: 조회하려는 데이터 구간 (데이터의 시작 시점과 종료 시점)
  • withPeriod: 조회하려는 데이터 구간 내에서의 데이터 간격. 예를들면 지난 1시간 동안 몇 분 간격으로 데이터를 조회할지를 의미. 초단위값
  • withDimensions: SQS의 경우 "QueueName" 하나만 있고, 이 값으로 어떤 sqs에 대한 데이터인지 구분 가능.

(참고: Available CloudWatch metrics for Amazon SQS)

 

설정값은 현재 지난 5분동안(from endTime to startTime) 5분간격(period)의 데이터를 조회하도록 되어있으므로 1개의 data point 가 조회가 됩니다. 그리고 unit은 초단위로 나옵니다.

위 코드를 실행해서 조회한 sqs의 Approximate Age Of Oldest Message 지표값은 다음과 같이 출력됩니다.

dataPoints: [{Timestamp: Thu Dec 29 16:08:00 KST 2022,Maximum: 249.0,Unit: Seconds,}]

 

설정값을 변경하여 period를 60으로 넣어서 실행하면 5개가 조회됩니다.

dataPoints: [{Timestamp: Thu Dec 29 17:03:00 KST 2022,Maximum: 3254.0,Unit: Seconds,}, {Timestamp: Thu Dec 29 17:07:00 KST 2022,Maximum: 3554.0,Unit: Seconds,}, {Timestamp: Thu Dec 29 17:05:00 KST 2022,Maximum: 3433.0,Unit: Seconds,}, {Timestamp: Thu Dec 29 17:06:00 KST 2022,Maximum: 3491.0,Unit: Seconds,}, {Timestamp: Thu Dec 29 17:04:00 KST 2022,Maximum: 3370.0,Unit: Seconds,}]

 

조회된 5개의 데이터는 지난 5분 구간(startTime, endTime)에서 1분 간격(period) 데이터를 조회했을 때의 결과입니다. 그리고 이 값은 Approximate Age Of Oldest Message, 즉, 대략적으로 얼마나 오래되었는가를 나타내는 값이므로 1분 간격 데이터를 조회한다면 약 1분(60초)의 시간차이가 있겠죠. 출력된 데이터의 순서가 시간순이 아니니 시간순으로 정렬해보면 약 1분 정도 차이가 난다는 것을 확인할 수 있습니다. 

[
    {Timestamp: Thu Dec 29 17:03:00 KST 2022,Maximum: 3254.0,Unit: Seconds,}, 
    {Timestamp: Thu Dec 29 17:04:00 KST 2022,Maximum: 3370.0,Unit: Seconds,}
    {Timestamp: Thu Dec 29 17:05:00 KST 2022,Maximum: 3433.0,Unit: Seconds,}, 
    {Timestamp: Thu Dec 29 17:06:00 KST 2022,Maximum: 3491.0,Unit: Seconds,}, 
    {Timestamp: Thu Dec 29 17:07:00 KST 2022,Maximum: 3554.0,Unit: Seconds,}, 
]

 

17:03 에서 17:04는 예외적으로 약 2분 차이가 나네요 ^^;;

이상으로 AWS cloudwatch API로 SQS의 metric을 조회하는 방법에 대해 알아보았습니다.

 

저는 이렇게 조회한 데이터를 가지고 일정 시간을 넘어설 경우 쓰레드 개수를 scale in/out 하도록 서비스를 구현했습니다.

 

도움이 되셨다면 공감꾹 부탁드려요~

 

운영환경에 이런저런 개발이 계속 진행되고 데이터도 쌓이고 하다보니 점점 무거워지고 있는 와중에 dba쪽에서 slow query 관련하여 문의가 들어왔고 확인하다보니 다른 이슈가 확인되었다. readOnly 트랜잭션으로 묶어놓은 쿼리인데 reader쪽에서 실행되어야 할 쿼리가 writer쪽에서도 실행이 되고 있는 현상이 지속되고 있었다.

 

현재 애플리케이션은 SpringBoot 2.x + MariaDB connector 2.7.x + HikariPool + MyBatis 사용하도록 구성된 상태.

compile 'org.mybatis.spring.boot:mybatis-spring-boot-starter:2.1.1'
compile 'org.springframework.boot:spring-boot-starter-jdbc'
compile 'org.mariadb.jdbc:mariadb-java-client:2.7.7'
compile 'org.bgee.log4jdbc-log4j2:log4jdbc-log4j2-jdbc4.1:1.16'

 

db 클러스터는 writer 1개와 reader 1개로 구성되어있다. 클러스터 주소는 writer, reader 용으로 각 1개씩 두 개가 있다.

  • my-cluster.cluster-xxx.ap-northeast-2.rds.amazonaws.com 
  • my-cluster.cluster-ro-xxx.ap-northeast-2.rds.amazonaws.com

 

그리고 아래와 같이 writer용과 reader용 주소가 별도로 있다.

  • my-cluster-01.xxx.ap-northeast-2.rds.amazonaws.com (writer)
  • my-cluster-02.xxx.ap-northeast-2.rds.amazonaws.com (reader)

 

굵게 표시한 클러스터 주소와 실제 DB주소의 차이는 확인하고 넘어가자.

 

그리고 jdbc url은 아래와 같이 writer 클러스터 주소만 넣어서 사용하고 있었다. 내가 이렇게 설정한건 아니었고 이렇게 해도 aurora 옵션을 쓸 경우 자동으로 reader쪽으로 readOnly 쿼리가 실행된다고 누군가가 그래서 뭐 그러려니 하고 있었는데 이런 이상한 현상이 확인된 것이다. ( >,.< )

spring:
  datasource:
    url: jdbc:mariadb:aurora://my-cluster.cluster-xxx.ap-northeast-2.rds.amazonaws.com

 

원인추적을 해보기 위해 일단 log4jdbc의 audit 설정을 좀 변경했다. @Transactional(readOnly=true) 설정이 제대로 안먹히는건가?? 싶어서 말이다. 

logging:
  level:
    jdbc:
      audit: debug

 

확인했을 때는 아래처럼 readOnly 설정은 정상적으로 되고 있었다.

DEBUG jdbc.audit : 1. Connection.setReadOnly(true) returned   com.zaxxer.hikari.pool.ProxyConnection.setReadOnly(ProxyConnection.java:423)
DEBUG jdbc.audit : 1. Connection.getAutoCommit() returned true  com.zaxxer.hikari.pool.HikariProxyConnection.getAutoCommit(HikariProxyConnection.java:-1)
DEBUG jdbc.audit : 1. Connection.setAutoCommit(false) returned   com.zaxxer.hikari.pool.ProxyConnection.setAutoCommit(ProxyConnection.java:414)
DEBUG jdbc.audit : 1. Connection.getAutoCommit() returned false

 

그럼 왜 이럴까? 다음으로는 jdbc url에 아래와 같이 log 파라미터를 추가하고 로거를 추가하여 mariaDB 쪽 로그를 확인해보았다.

spring:
  datasource:
    url: jdbc:mariadb:aurora://my-cluster.cluster-xxx.ap-northeast-2.rds.amazonaws.com?log=true

 

<logger name="org.mariadb.jdbc" level="info">
    <appender-ref ref="stdout"/>
</logger>

 

DEBUG 88239 --- [nio-8080-exec-1] org.mariadb.jdbc.MariaDbConnection       : conn=817636(M) - set read-only to value true
DEBUG 88239 --- [nio-8080-exec-1] o.m.j.i.protocol.AbstractQueryProtocol   : System variable change :  autocommit = OFF
{{쿼리 실행}}
DEBUG 88239 --- [nio-8080-exec-1] o.m.j.i.protocol.AbstractQueryProtocol   : System variable change :  autocommit = ON
DEBUG 88239 --- [nio-8080-exec-1] org.mariadb.jdbc.MariaDbConnection       : conn=53856(S) - set read-only to value false

 

로그상으로는 도대체 실제로 어느 클러스터 주소에서 쿼리가 실행되는지 알 수가 없었다.

그래서 운영환경에서 사용하고있는 mariaDB 커넥터와 동일한 버전의 소스코드에 로그를 여기저기 추가하면서 추적을 시작했고,

다음과 같은 현상을 확인했다.

  1. writer 클러스터 주소를 기준으로 신규 커넥션을 생성된다. 
  2. readOnly 쿼리가 writer쪽에서 실행된 뒤에 failover 프로세스가 실행되면서 mariaDB FailoverLoop에서 reader쪽 커넥션이 생성되어 pool에 들어간다.
  3. 이후의 readOnly 쿼리들은 정상적으로 reader쪽에서 실행된다.

 

이제 궁금한 점이 생겼다.

  1. 커넥션의 생성주기에 따라 신규 커넥션을 생성하게되면 reader쪽 커넥션은 사라지는지?
  2. 신규 커넥션 생성시 reader host가 포함되도록 할 수 있을지..? (이렇게 할 수 있으면 1번과 같은 현상은 없어질테니)
  3. 그렇게하면 readOnly 쿼리가 항상 reader로 들어가는지?

 

1번 케이스의 경우 maxLifeTime 설정값을 30초로 설정해서 테스트해보았고, reader쪽 커넥션은 사라지게된다. readOnly 쿼리가 reader에서 실행되려면 위에 말한 failover 과정이 다시 필요하다. 즉, maxLifeTime이 지나 커넥션을 새로 생성하게 될 경우 failover 프로세스가 실행되어야 reader를 사용할 수 있게 된다. (아래 2번 케이스에 대한 내용까지 확인하면 알겠지만 어디까지나 url 설정에 메인 클러스터 주소만 넣었을 경우이다.)

 

2번 케이스의 경우 jdbc url 설정에 reader 클러스터의 주소를 추가해주면 된다. 기존 설정과 변경한 설정은 다음과 같다.

spring:
  datasource:
    url: jdbc:mariadb:aurora://my-cluster.cluster-xxx.ap-northeast-2.rds.amazonaws.com

 

spring:
  datasource:
    url: jdbc:mariadb:aurora://my-cluster.cluster-xxx.ap-northeast-2.rds.amazonaws.com,my-cluster.cluster-ro-xxx.ap-northeast-2.rds.amazonaws.com

이렇게 reader cluster의 주소가 추가된 jdbc url을 사용할 경우 항상 reader 클러스터쪽으로 readOnly 쿼리가 실행되는 것을 확인할 수 있었다. 혹시라도 url 뒤쪽에 파라미터값을 사용한다면 파라미터값들은 제일 마지막에 한번만 붙여주면 된다. 예를들어 파라미터값을 아래처럼 넣게되면 mariaDB 커넥터에서 url 파싱할 때 뒤 쪽 url이 사라지게 되니 주의!!! 즉, 모든 클러스터에 동일한 파라미터값을 사용해야 한다는 것 !!

url: my-cluster.cluster-xxx.ap-northeast-2.rds.amazonaws.com?log=true,my-cluster.cluster-ro-xxx.ap-northeast-2.rds.amazonaws.com?log=true

 

그냥 얼핏 듣기로는 메인클러스터 주소만 넣어주소 jdbc url에 aurora 옵션을 넣어줄 경우 readOnly 트랜잭션은 자동으로 reader 쪽으로 들어간다고 들었었으나 그렇지 않다는 것을 확인한 디버깅이었다.

 

결국 결론은 이렇다. 클러스터 주소가 writer, reader가 별도로 있을 경우 (아마 AWS aurora를 클러스터링해서 사용할 경우 다 이럴 것이다) 개발자 입장에서는 writer, reader 두 클러스터 주소를 jdbc url에 넣어주어야 readOnly 트랜잭션이 항상 정상적으로 reader 클러스터에서 실행되게 된다.

 

참고로...mariaDB connector 3.x 버전에서는 aurora 옵션을 지원하지 않는단다...

 

💻 Programming/Java

[Java] 스트림을 이용한 소수 구하기

요즘 이펙티브 자바 Third 에디션 책을 동네 도서관에서 대여해서 읽고있습니다.

스트림 병렬화에 대한 글을 읽다가 소수구하는 로직을 스트림으로 작성한 부분을 보게되었습니다.

소수구하기 로직은 이직준비 할 때나 다시 들여다볼만한거라 오래전에 for-loop 로 구현해본 기억만 있다보니 신선하게 느껴졌네요.

아직도 많은 블로그들에서 for-loop를 이용한 방법들만 많이 소개하고 있기도 하고해서 포스팅 주제로 삼아봤습니다. 

개인적인 기록도 할겸...

책을 읽고 새로 알게된 부분은 스트림에 대한 부분도 있지만 이미 BigInteger 클래스에 isProbablePrime 이란 메서드가 있었다는 겁니다..

 

아래는 특정 숫자 n 까지 소수가 몇 개인지를 출력하고, 그 목록도 출력하는 것을 테스트한 코드입니다.

public static void main(String[] args) {
    int n = (int) Math.pow(10, 8);
    // n 까지의 수 중에 소수의 개수 출력하기
    long cnt = LongStream.rangeClosed(2, n)
    	    .parallel()
            .mapToObj(BigInteger::valueOf)
            .filter(i -> i.isProbablePrime(50))
            .count();
    System.out.println(cnt);

    // n 까지의 수 중에 소수 목록 출력하기
    System.out.println(LongStream.rangeClosed(2, n)
            .mapToObj(BigInteger::valueOf)
            .filter(i -> i.isProbablePrime(50))
            .collect(Collectors.toList()));
}

LongStream을 이용하여 숫자의 범위를 정하고 mapToObj 를 이용하여 BigInteger로 변형한뒤 BigInteger.isProbablePrime(int certainty) 메서드를 필터로 전달하여 소수를 구하고 있습니다.

BigInteger.isProbablePrime(int certainty) 메서드는 소수를 구하기위해 내부적으로 밀러-라빈(Miller-Rabin) 테스트와 루카스-레머(Lucas-Lehmer) 테스트를 사용하고 있고요. 여기서 사용된 밀러라빈 테스트는 DSA(Digital Signiture Algorithm) 스펙 (NIST FIPS 186-2)을 기반으로 했다고 합니다. 이 스펙은 파일로 첨부하니 관심있으신 분들은 다운받아 보셔도 될 것 같네요. 

 

fips186-2.pdf
0.35MB

 

참고로 .parallel() 은 스트림에서 사용할 때 매우 주의를 요하는 기능입니다. 책에서는 이렇게 얘기합니다. Stream.iterate 를 데이터 소스로 이용하거나 중간 연산으로 limit 을 사용하는 스트림 파이프라인에서는 parallel을 이용한 성능개선을 기대할 수 없으며 오히려 안좋아질 수도 있다고 말이죠. 실제로 운영환경에서 저것 때문에 이슈가 발생한 적도 있었습니다. 그냥 무한루프에 빠진것처럼 쓰레드 하나가 먹통이 되어버리더군요. 스트림에서 병렬연산에 적합한 적은 reduce, min, max, count, sum 등의 연산이며, collect처럼 가변축소를 수행하는 메서드는 병렬연산에 적합하지 않다고 합니다. 참고하시기 바랍니다.

지난 포스팅에서 요청과 응답에 대한 로그를 남기는 법에 대해서 알아보았었는데요

이어서 이번에는 출력되는 로그메시지의 내용을 바꿔보려고 합니다.

 

혹시라도 검색으로 이 포스팅을 먼저 보게되시는 분은 아래 포스팅을 먼저 읽어보시길 추천드립니다.

[5분코딩] Filter를 이용한 요청,응답 로깅 (How to log request, response info inlcuding payload using filter) - (1/2)

 

로그 메시지 내맘대로 꾸미기

우선 지난 시간에 마지막으로 확인한 로그 출력 내용을 다시 확인해보면 아래와 같습니다.

2022-09-16 07:32:49.190  INFO 31518 --- [nio-8080-exec-5] c.k.demo.filter.RequestLoggingFilter     : Before request [POST /test/request-body-log, client=0:0:0:0:0:0:0:1]
2022-09-16 07:32:49.226  INFO 31518 --- [nio-8080-exec-5] c.k.demo.filter.RequestLoggingFilter     : After request [POST /test/request-body-log, client=0:0:0:0:0:0:0:1, payload={
    "id":1000,
    "name":"케이치",
    "age":20
}]

 

그럼 저 메시지를 어떻게 바꿀 수 있을지 한번 알아볼게요.

요청/응답 로깅을 위해서 우리는 AbstractRequestLoggingFilter 를 상속하여 필터를 하나 만들었었습니다.

로그 메시지를 바꾸려면 저 클래스에서 어떤 메서드들을 제공하고 있는지 들여다봐야 합니다. 

AbstractRequestLoggingFilter를 까보면 아래 메서드를 오버라이드해서 재정의하고 있는 것을 볼 수 있습니다.

protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain)

 

doFilterInternal 메서드에서 하는 일은 요청에 대한 비즈니스 로직이 실행되기 전후로 로그를 남기는 것입니다.

코드를 잠시 살펴볼게요

@Override
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain)
      throws ServletException, IOException {

   boolean isFirstRequest = !isAsyncDispatch(request);
   HttpServletRequest requestToUse = request;

   if (isIncludePayload() && isFirstRequest && !(request instanceof ContentCachingRequestWrapper)) {
      requestToUse = new ContentCachingRequestWrapper(request, getMaxPayloadLength());
   }

   boolean shouldLog = shouldLog(requestToUse);
   if (shouldLog && isFirstRequest) {
      beforeRequest(requestToUse, getBeforeMessage(requestToUse));
   }
   try {
      filterChain.doFilter(requestToUse, response);
   }
   finally {
      if (shouldLog && !isAsyncStarted(requestToUse)) {
         afterRequest(requestToUse, getAfterMessage(requestToUse));
      }
   }
}

 

beforeRequest(requestToUse, getBeforeMessage(requestToUse)) 에서 Before request ... 로그를 남기고 있고

afterRequest(requestToUse, getAfterMessage(requestToUse)) 에서 After request ... 로그를 남기고 있습니다.

따라서 우리가 원하는대로 메시지의 내용을 바꾸려면 저 두 군데를 수정해주면 됩니다.

 

우선 로그 메시지에 대한 수정 요구사항이 아래와 같다고 가정해보겠습니다.

  1. 호출받은 API 정보와 클라이언트IP 정보를 중복 출력 하지 않는다
  2. 호출받은 API uri 와 클라이언트IP, payload 정보는  before request 에서 남긴다.  🌟
  3. after request 에는 응답소요시간과 http status 코드값을 남긴다.
  4. 최종적으로 출력되는 모습은 다음과 같다.
2022-09-16 08:28:08.053  INFO 41196 --- [nio-8080-exec-2] c.k.demo.filter.RequestLoggingFilter     : REQ: POST uri=/test/request-body-log;client=0:0:0:0:0:0:0:1;payload={
    "id":1000,
    "name":"케이치",
    "age":20
}
2022-09-16 08:28:08.076  INFO 41196 --- [nio-8080-exec-2] c.k.demo.filter.RequestLoggingFilter     : RES: 22ms, 400

 

자, 이제 위 요구사항에 맞게 우리의 필터클래스를 수정해보겠습니다. 

RequestLoggingFilter 클래스에 아래 코드를 추가해주세요.

@Override
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain)
        throws ServletException, IOException {

    boolean isFirstRequest = !isAsyncDispatch(request);
    HttpServletRequest requestToUse = request;

    if (isIncludePayload() && isFirstRequest && !(request instanceof ContentCachingRequestWrapper)) {
        requestToUse = new ContentCachingRequestWrapper(request);
    }

    long start = System.currentTimeMillis();

    if (isFirstRequest) {
        beforeRequest(requestToUse, getBeforeMessage(requestToUse));
    }

    try {
        filterChain.doFilter(requestToUse, response);
    } finally {
        if (!isAsyncStarted(requestToUse)) {
            afterRequest(requestToUse, getAfterMessage(System.currentTimeMillis() - start, response.getStatus()));
        }
    }
}

private String getBeforeMessage(HttpServletRequest request) {
    return createMessage(request, "REQ: ", "");
}

private String getAfterMessage(long elapsed, int status) {
    return "RES: " + elapsed + "ms, " + status;
}

 

AbstractRequestLoggingFilter 에 구현되어있는 doFilterInternal 메서드 내용을 그대로 가지고와서 beforeRequest와 afterRequest 메서드의 두 번째 파라미터로 전달하는 message 를 조립하는 메서드를 직접 구현합니다. getBeforeMessage의 createMessage는 super클래스, 즉, AbstractRequestLoggingFilter 에서 제공하는 것을 그대로 사용합니다. createMessage 에서는 prefix와 suffix 그리고 request 정보를 가지고 메시지를 알아서 만들어 줍니다. payload도 역시 여기 포함되어있죠.

자, 그럼 앱을 재기동하고 로깅이 어떻게 되는지 보겠습니다.

2022-09-16 08:39:20.270  INFO 43287 --- [nio-8080-exec-1] c.k.demo.filter.RequestLoggingFilter     : REQ: POST /test/request-body-log, client=0:0:0:0:0:0:0:1
2022-09-16 08:39:20.306  INFO 43287 --- [nio-8080-exec-1] c.k.demo.filter.RequestLoggingFilter     : RES: 35ms, 200

 

요구사항 대부분이 반영된 것을 확인할 수 있습니다. 어라? 근데 payload 가 request 로그에서 빠져있습니다.

분명 after message 로그가 출력될 때는 잘 출력이 됐었는데 말이죠. 똑같은 createMessage 메서드를 이용했는데 before request 에서는 payload가 출력이 안됩니다 ㅜㅜ

확인해보니 AbstractRequestLoggingFilter.getMessagePayload 에서 아래 wrapper 가 null 로 반환이 되고있었습니다.

ContentCachingRequestWrapper wrapper =
      WebUtils.getNativeRequest(request, ContentCachingRequestWrapper.class);

 

res로그에서는 잘 나오던게 req로그에서 출력하려니 null이 반환이 됩니다.

이걸 해결하려면 추가적인 작업이 필요한데 우선 아래 두 개의 클래스를 추가해줍니다.

package com.keichee.demo.filter;

import org.springframework.stereotype.Component;
import org.springframework.web.filter.GenericFilterBean;

import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletRequest;
import java.io.IOException;

@Component
public class RequestBodyCacheFilter extends GenericFilterBean {

    @Override
    public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain chain)
            throws IOException, ServletException {
        chain.doFilter(new RequestBodyCacheWrapper((HttpServletRequest) servletRequest), servletResponse);
    }
}

 

package com.keichee.demo.filter;

import lombok.extern.slf4j.Slf4j;

import javax.servlet.ReadListener;
import javax.servlet.ServletInputStream;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletRequestWrapper;
import java.io.*;
import java.nio.charset.StandardCharsets;

@Slf4j
public class RequestBodyCacheWrapper extends HttpServletRequestWrapper {

    private final ByteArrayInputStream byteArrayInputStream;

    public RequestBodyCacheWrapper(HttpServletRequest request) throws IOException {
        super(request);
        InputStream is = super.getInputStream();
        byteArrayInputStream = new ByteArrayInputStream(is.readAllBytes());
    }

    @Override
    public ServletInputStream getInputStream() {
        byteArrayInputStream.reset();
        return new MyServletInputStream(byteArrayInputStream);
    }

    @Override
    public BufferedReader getReader() {
        byteArrayInputStream.reset();
        return new BufferedReader(new InputStreamReader(byteArrayInputStream, StandardCharsets.UTF_8));
    }


    private static class MyServletInputStream extends ServletInputStream {

        private final InputStream is;

        public MyServletInputStream(InputStream bis) {
            is = bis;
        }

        @Override
        public int read() throws IOException {
            return is.read();
        }

        @Override
        public int read(byte[] b) throws IOException {
            return is.read(b);
        }

        @Override
        public boolean isFinished() {
            return false;
        }

        @Override
        public boolean isReady() {
            return false;
        }

        @Override
        public void setReadListener(ReadListener readListener) {
        }
    }
}

 

이제 다시 RequestLoggingFilter 클래스로 돌아와서 AbstractRequestLoggingFilter.createMessage 메서드를 그대로 복사해서 가지고 옵니다. 그리고 getMessagePayload 부분을 아래와 같이 수정해주세요. 다른 부분은 그대로 놔둡니다.

String payload = null;
try {
    payload = new String(request.getInputStream().readAllBytes(), StandardCharsets.UTF_8);
} catch (IOException e) {
    log.error("failed to read payload", e);
}

 

 

수정이 완료된 createMessage 메서드는 아래와 같습니다.

@Override
protected String createMessage(HttpServletRequest request, String prefix, String suffix) {
    StringBuilder msg = new StringBuilder();
    msg.append(prefix);
    msg.append(request.getMethod()).append(' ');
    msg.append(request.getRequestURI());

    if (isIncludeQueryString()) {
        String queryString = request.getQueryString();
        if (queryString != null) {
            msg.append('?').append(queryString);
        }
    }

    if (isIncludeClientInfo()) {
        String client = request.getRemoteAddr();
        if (StringUtils.hasLength(client)) {
            msg.append(", client=").append(client);
        }
        HttpSession session = request.getSession(false);
        if (session != null) {
            msg.append(", session=").append(session.getId());
        }
        String user = request.getRemoteUser();
        if (user != null) {
            msg.append(", user=").append(user);
        }
    }

    if (isIncludeHeaders()) {
        HttpHeaders headers = new ServletServerHttpRequest(request).getHeaders();
        if (getHeaderPredicate() != null) {
            Enumeration<String> names = request.getHeaderNames();
            while (names.hasMoreElements()) {
                String header = names.nextElement();
                if (!getHeaderPredicate().test(header)) {
                    headers.set(header, "masked");
                }
            }
        }
        msg.append(", headers=").append(headers);
    }

    if (isIncludePayload()) {
        String payload = null;
        try {
            payload = new String(request.getInputStream().readAllBytes(), StandardCharsets.UTF_8);
        } catch (IOException e) {
            log.error("failed to read payload", e);
        }
        if (payload != null) {
            msg.append(", payload=").append(payload);
        }
    }

    msg.append(suffix);
    return msg.toString();
}

 

마지막으로 doFilterInternal 메서드 로직 중 filterChain.doFilter에서 사용하는 request 객체를 ContentCachingRequestWrapper 가 아닌 메서드 파라미터로 전달받은 request를 그대로 사용하도록 수정합니다. (reuqestToUse -> request)

최종적으로 RequestLoggingFilter 클래스의 소스코드는 다음과 같습니다.

package com.keichee.demo.filter;

import lombok.extern.slf4j.Slf4j;
import org.springframework.http.HttpHeaders;
import org.springframework.http.server.ServletServerHttpRequest;
import org.springframework.util.StringUtils;
import org.springframework.web.filter.AbstractRequestLoggingFilter;
import org.springframework.web.util.ContentCachingRequestWrapper;

import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import javax.servlet.http.HttpSession;
import java.io.IOException;
import java.nio.charset.StandardCharsets;
import java.util.Enumeration;

@Slf4j
public class RequestLoggingFilter extends AbstractRequestLoggingFilter {

    @Override
    protected void beforeRequest(HttpServletRequest request, String message) {
        logger.info(message);
    }

    @Override
    protected void afterRequest(HttpServletRequest request, String message) {
        logger.info(message);
    }

    @Override
    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain)
            throws ServletException, IOException {

        boolean isFirstRequest = !isAsyncDispatch(request);
        HttpServletRequest requestToUse = request;

        if (isIncludePayload() && isFirstRequest && !(request instanceof ContentCachingRequestWrapper)) {
            requestToUse = new ContentCachingRequestWrapper(request);
        }

        long start = System.currentTimeMillis();

        if (isFirstRequest) {
            beforeRequest(requestToUse, getBeforeMessage(requestToUse));
        }

        try {
            filterChain.doFilter(request, response);
        } finally {
            if (!isAsyncStarted(requestToUse)) {
                afterRequest(requestToUse, getAfterMessage(System.currentTimeMillis() - start, response.getStatus()));
            }
        }
    }

    private String getBeforeMessage(HttpServletRequest request) {
        return createMessage(request, "REQ: ", "");
    }

    private String getAfterMessage(long elapsed, int status) {
        return "RES: " + elapsed + "ms, " + status;
    }

    @Override
    protected String createMessage(HttpServletRequest request, String prefix, String suffix) {
        StringBuilder msg = new StringBuilder();
        msg.append(prefix);
        msg.append(request.getMethod()).append(' ');
        msg.append(request.getRequestURI());

        if (isIncludeQueryString()) {
            String queryString = request.getQueryString();
            if (queryString != null) {
                msg.append('?').append(queryString);
            }
        }

        if (isIncludeClientInfo()) {
            String client = request.getRemoteAddr();
            if (StringUtils.hasLength(client)) {
                msg.append(", client=").append(client);
            }
            HttpSession session = request.getSession(false);
            if (session != null) {
                msg.append(", session=").append(session.getId());
            }
            String user = request.getRemoteUser();
            if (user != null) {
                msg.append(", user=").append(user);
            }
        }

        if (isIncludeHeaders()) {
            HttpHeaders headers = new ServletServerHttpRequest(request).getHeaders();
            if (getHeaderPredicate() != null) {
                Enumeration<String> names = request.getHeaderNames();
                while (names.hasMoreElements()) {
                    String header = names.nextElement();
                    if (!getHeaderPredicate().test(header)) {
                        headers.set(header, "masked");
                    }
                }
            }
            msg.append(", headers=").append(headers);
        }

        if (isIncludePayload()) {
            String payload = null;
            try {
                payload = new String(request.getInputStream().readAllBytes(), StandardCharsets.UTF_8);
            } catch (IOException e) {
                log.error("failed to read payload", e);
            }
            if (payload != null) {
                msg.append(", payload=").append(payload);
            }
        }

        msg.append(suffix);
        return msg.toString();
    }

}

 

자, 이제 앱을 재기동하고 다시 API를 호출해보겠습니다.

2022-09-16 10:04:36.918 DEBUG 57590 --- [           main] com.keichee.demo.DemoLoggingApplication  : Running with Spring Boot v2.7.3, Spring v5.3.22
2022-09-16 10:04:36.918  INFO 57590 --- [           main] com.keichee.demo.DemoLoggingApplication  : The following 1 profile is active: "local"
2022-09-16 10:04:37.301 DEBUG 57590 --- [           main] c.k.demo.filter.RequestBodyCacheFilter   : Filter 'requestBodyCacheFilter' configured for use
2022-09-16 10:04:37.301 DEBUG 57590 --- [           main] c.k.demo.filter.RequestLoggingFilter     : Filter 'loggingFilter' configured for use
2022-09-16 10:04:37.416  INFO 57590 --- [           main] com.keichee.demo.DemoLoggingApplication  : Started DemoLoggingApplication in 0.642 seconds (JVM running for 0.873)
2022-09-16 10:04:39.588  INFO 57590 --- [nio-8080-exec-2] c.k.demo.filter.RequestLoggingFilter     : REQ: POST /test/request-body-log, client=0:0:0:0:0:0:0:1, payload={
    "id":1000,
    "name":"케이치",
    "age":20
}
2022-09-16 10:04:39.627  INFO 57590 --- [nio-8080-exec-2] c.k.demo.filter.RequestLoggingFilter     : RES: 40ms, 200

 

request payload가 정상적으로 출력되는 것을 확인할 수 있습니다. 응답 status도 200이 나온것을 확인했습니다.

 

자, 잘 따라 오셨나요? 

이 부분은 tricky한 부분이라 비즈니스 로직이 실행되기 전에 request body를 출력하는 부분에서 애를 먹는 분들이 많습니다. stackoverflow에서 해결책을 찾기도 힘들더군요. 의도한건지는 모르겠으나 springboot에 내장된 tomcat에 request body를 한번만 읽어서 쓸 수 있도록 제한(?)되어있기 때문에 잘못 설정하면 로그에는 payload가 잘 출력되지만 비즈니스로직 실행시 request body를 못 읽어와서 400 bad request가 발생하기도 합니다.

 

이상으로 request, response 로그를 내맘대로 바꿔보는 방법에 대해서 알아보았습니다.

 

읽어주셔서 감사합니다~ 🙇

좋아요 꾹 눌러주고 가세요~ 

개발자로서 운영이슈를 해결하기 위해서는 로그메시지가 디버깅을 위해서 꼭 필요하다는건 누구나 알고계실겁니다.

하지만 로깅을 잘 하기 위해서는 많은 고민이 필요합니다.

로그레벨은 어떻게 할지 로그의 내용은 어떤 정보들로 채워넣을지 등등 말이죠.

로그는 많이 남긴다고 좋은게 아니죠.

어떤 분들은 아무런 의미도 없는 정보를 로깅하기도 합니다.

비용적인 측면이 문제되지 않는다면 대량의 로그를 마음껏 남겨도 되겠지만 현실은 그렇지 않죠.

따라서 중요도에 따라서 적당~~히 최소한의 내용만 로깅하는게 좋습니다.

로그 중에서 가장 중요한 로그는 요청과 응답에 대한 것입니다.

API 요청시 어떤 정보를 전달받았는지에 대한 request log과

그 데이터를 기준으로 비즈니스 로직을 태운 뒤에 어떤 응답을 내주었는지

response log 만 있어도 디버깅은 충분히 가능하죠.

물론 요청과 응답 중간에 로직이 복잡하다면 중간중간 추가적인 로그를 심어주는게 많은 도움이 될 수 있습니다.

 

그래서 이번 포스팅에서는 요청과 응답을 어떻게 로깅하는지에 대해 공유드리고자 합니다.

 

1. 프로젝트 생성

 

기본적인 개발환경은 아래와 같습니다.

  • IntelliJ IDEA 2021.3.3 (Ultimate Edition)
  • SpringBoot 2.7.3
  • Java 18 (OpenJDK)

자, 우선 깡통 프로젝트를 만들겠습니다.

자, 깡통 프로젝트가 완성되었습니다. 

 

2. 라이브러리 추가

이제 개발편의를 위해 lombok과 로깅을 위한 logback 라이브러리를 추가하고, API 개발을 위해 spring-boot-starter-web 라이브러리를 추가하겠습니다.

implementation 'org.springframework.boot:spring-boot-starter-web'
implementation 'org.projectlombok:lombok:1.18.24'
annotationProcessor 'org.projectlombok:lombok:1.18.24'
implementation 'ch.qos.logback:logback-classic:1.2.11'

 

3. API 작성

그리고 아래와 같이 테스트용 컨트롤러를 하나 작성해줍니다.

package com.keichee.demo.controller;

import lombok.extern.slf4j.Slf4j;
import org.springframework.web.bind.annotation.*;

@Slf4j
@RestController
@RequestMapping("/test")
public class TestController {

    @GetMapping("/log")
    public int requestResponseLog(@RequestParam int code) {
        log.info("requestResponseLog method called with code {}", code);
        return code;
    }
}

 

여기까지하고 앱을 기동한 뒤 API를 호출하여 로그가 잘 남는지 확인해볼게요.

2022-09-15 17:04:50.580  INFO 92637 --- [           main] com.keichee.demo.DemoLoggingApplication  : No active profile set, falling back to 1 default profile: "default"
2022-09-15 17:04:51.034  INFO 92637 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2022-09-15 17:04:51.038  INFO 92637 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-09-15 17:04:51.038  INFO 92637 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.65]
2022-09-15 17:04:51.105  INFO 92637 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-09-15 17:04:51.107  INFO 92637 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 495 ms
2022-09-15 17:04:51.306  INFO 92637 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2022-09-15 17:04:51.312  INFO 92637 --- [           main] com.keichee.demo.DemoLoggingApplication  : Started DemoLoggingApplication in 0.879 seconds (JVM running for 1.294)
2022-09-15 17:05:56.173  INFO 92637 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2022-09-15 17:05:56.173  INFO 92637 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2022-09-15 17:05:56.174  INFO 92637 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 1 ms
2022-09-15 17:05:56.186  INFO 92637 --- [nio-8080-exec-1] c.k.demo.controller.TestController       : requestResponseLog method called with code 2

 

제일 마지막줄에 보면 TestController에서 출력한 로그가 보이네요.

비즈니스 로직의 로그는 잘 출력되고 있으니 이제 기본적인 준비가 끝났습니다.

 

4. Filter 구현

요청과 응답에 대한 로그출력을 위해서 우리는 Filter를 이용할 겁니다. 

spring-web에서는 아래와 같이 여러 종류의 filter를 제공하고 있습니다.

AbstractRequestLoggingFilter
CharacterEncodingFilter
CommonsRequestLoggingFilter
CompositeFilter
CorsFilter
DelegatingFilterProxy
FormContentFilter
ForwardedHeaderFilter
GenericFilterBean
HiddenHttpMethodFilter
HttpPutFormContentFilter
OncePerRequestFilter
RelativeRedirectFilter
RelativeRedirectResponseWrapper
RequestContextFilter
ServletContextRequestLoggingFilter
ServletRequestPathFilter
ShallowEtagHeaderFilter

 

여기서 request logging과 관련된 filter는 AbstractRequestLoggingFilter, CommonsRequestLoggingFilter, 그리고 ServletContextRequestLoggingFilter 가 있습니다.

우리는 AbstractRequestLoggingFilter를 상속해서 우리만의 필터를 만들어 볼거에요.

com.keichee.demo 패키지 아래에 filter 패키지를 만들고 이 안에 RequestLoggingFilter 라는 클래스를 아래와 같이 만들어주세요

package com.keichee.demo.filter;

import lombok.extern.slf4j.Slf4j;
import org.springframework.web.filter.AbstractRequestLoggingFilter;
import org.springframework.web.util.ContentCachingRequestWrapper;

import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;

@Slf4j
public class RequestLoggingFilter extends AbstractRequestLoggingFilter {

    @Override
    protected void beforeRequest(HttpServletRequest request, String message) {
        logger.info(message);
    }

    @Override
    protected void afterRequest(HttpServletRequest request, String message) {
        logger.info(message);
    }
}

 

이제 이 필터를 빈으로 등록해줘야 합니다.

com.keichee.demo 패키지 아래에 config 패키지를 만들고 이 안에 RequestLoggingConfig 클래스를 만들겠습니다.

package com.keichee.demo.config;

import com.keichee.demo.filter.RequestLoggingFilter;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;

@Configuration
public class RequestLoggingConfig {

    public static int MAX_PAYLOAD_LENGTH = 1000;

    @Bean
    public RequestLoggingFilter loggingFilter() {
        RequestLoggingFilter filter = new RequestLoggingFilter();
        filter.setIncludeClientInfo(true);
        filter.setIncludeHeaders(false);
        filter.setIncludePayload(true);
        filter.setIncludeQueryString(true);
        filter.setMaxPayloadLength(MAX_PAYLOAD_LENGTH);
        return filter;
    }
}

 

헤더정보 로깅이 필요할 경우 setIncludeHeaders(true)로 설정해주시면 됩니다.

payload의 max length는 로깅량과 로그를 저장하는 시스템의 용량 등에 따라 적당히 설정해주시면됩니다. 

 

이제 마지막 한스텝이 남았습니다.

logback-spring.xml 파일을 resources 디렉토리에 추가해줍니다.

<?xml version="1.0" encoding="UTF-8"?>

<configuration>

    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    <include resource="org/springframework/boot/logging/logback/console-appender.xml"/>

    <springProfile name="local">
        <logger name="com.keichee.demo" level="debug" additivity="false">
            <appender-ref ref="CONSOLE"/>
        </logger>

        <root level="error">
            <appender-ref ref="CONSOLE"/>
        </root>
    </springProfile>

</configuration>

 

지금까지 작성한 파일들을 포함하여 최종적으로 패키지 트리를 보면 아래와 같습니다.

이제 active profile 값에 local 을 주고 앱을 재기동한뒤 필터가 정상적으로 적용되었는지 확인해보겠습니다.

2022-09-16 07:28:54.399 DEBUG 31518 --- [           main] com.keichee.demo.DemoLoggingApplication  : Running with Spring Boot v2.7.3, Spring v5.3.22
2022-09-16 07:28:54.399  INFO 31518 --- [           main] com.keichee.demo.DemoLoggingApplication  : The following 1 profile is active: "local"
2022-09-16 07:28:54.751 DEBUG 31518 --- [           main] c.k.demo.filter.RequestLoggingFilter     : Filter 'loggingFilter' configured for use
2022-09-16 07:28:54.866  INFO 31518 --- [           main] com.keichee.demo.DemoLoggingApplication  : Started DemoLoggingApplication in 0.607 seconds (JVM running for 0.819)

출력되는 로그 중에 Filter 'loggingFilter' configured for use 가 출력된걸로 보아 정상적으로 적용이 된 것으로 확인됩니다.

 

이제 기존에 만들어 두었던 API를 다시 호출해보겠습니다.

2022-09-16 07:29:18.541  INFO 31518 --- [nio-8080-exec-2] c.k.demo.filter.RequestLoggingFilter     : Before request [GET /test/log?code=2, client=0:0:0:0:0:0:0:1]
2022-09-16 07:29:18.550  INFO 31518 --- [nio-8080-exec-2] c.k.demo.controller.TestController       : requestResponseLog method called with code 2
2022-09-16 07:29:18.560  INFO 31518 --- [nio-8080-exec-2] c.k.demo.filter.RequestLoggingFilter     : After request [GET /test/log?code=2, client=0:0:0:0:0:0:0:1]

요청에 대한 정보 uri와 query parameter 그리고 client에 X-Forwarded-For 값이 출력된 것을 볼 수 있고, 비즈니스 로직 실행이 끝난 뒤 소요시간이 얼마인지 http status 값이 뭔지 출력되는 것을 확인할 수 있습니다.

 

지금까지 요청에 대한 uri, query parameter와 API를 요청한 클라이언트의 IP 를 출력하고,

응답을 주기까지의 소요시간과 응답 상태값을 로깅하도록 설정을 해보았습니다. 여기까지 잘 따라 오셨나요? 😋

 

이제 request body 를 입력받아 payload가 잘 출력되는지 보겠습니다.

TestController 에 request body를 받는 API를 하나 추가하겠습니다.

@PostMapping("/request-body-log")
public long requestBodyLog(@RequestBody Employee employee) {
    return employee.getId();
}

Employee 정보를 받아서 id를 그대로 리턴해주는 간단한 API입니다. (어차피 request body 로깅을 위한거니 심플하게 

 

그리고 domain 패키지 하위에 Employee 클래스를 아래와 같이 생성해주겠습니다.

@Getter
@Setter
@FieldDefaults(level = AccessLevel.PRIVATE)
public class Employee {
    long id;
    String name;
    int age;
}

 

이제  앱을 기동해서 postman으로 테스트를 해보겠습니다.

 

로그는 아래와 같이 출력되었습니다.

2022-09-16 07:32:49.190  INFO 31518 --- [nio-8080-exec-5] c.k.demo.filter.RequestLoggingFilter     : Before request [POST /test/request-body-log, client=0:0:0:0:0:0:0:1]
2022-09-16 07:32:49.226  INFO 31518 --- [nio-8080-exec-5] c.k.demo.filter.RequestLoggingFilter     : After request [POST /test/request-body-log, client=0:0:0:0:0:0:0:1, payload={
    "id":1000,
    "name":"케이치",
    "age":20
}]

 

그런데 로그를 보니 uri 정보와 client 정보가 중복되서 출력이 되고 있고, request body로 넘겨준 데이터가 비즈니스 로직이 모두 실행되고 난 뒤에 출력되는 After request ... 부분에 출력이 되고 있습니다. 뭔가 출력되는 내용이 마음에 들지 않네요. 

 

다음 포스팅에서는 로그메시지를 바꿔보도록 하겠습니다.

 

읽어주셔서 감사합니다~ 🙇

 

도움이 되셨다면 좋아요 꾹 눌러주고 가세요~

 

[ 다음 포스팅 바로 읽기 ]

 

[5분코딩] Filter를 이용한 요청,응답 로깅 (How to log request, response info inlcuding payload using filter) - (2/2)

지난 포스팅에서 요청과 응답에 대한 로그를 남기는 법에 대해서 알아보았었는데요 이어서 이번에는 출력되는 로그메시지의 내용을 내맘대로 바꿔보려고 합니다. 혹시라도 검색으로 이 포스팅

keichee.tistory.com

 

💻 Programming/Java

[5분코딩] Spring Boot Cache with EHCACHE

안녕하세요~ 오랜만에 포스팅을 하게되네요.

오늘은 스프링부트 기반의 프로젝트에서 스프링캐시를 사용하는 방법에 대해서 공유드리려고 합니다.

스프링캐시는 레디스, 카페인, ehcache 등과 연계하여 사용하게 되는데요,

이번  포스팅에서는 ehcache와 연동하여 사용할 예정입니다.

우선 기본적인 개발환경은 아래와 같습니다.

  • IntelliJ IDEA 2021.3.3 (Ultimate Edition)
  • SpringBoot 2.7.3
  • Java 18 (OpenJDK)

1. 프로젝트 생성

우선 빈 깡통 프로젝트를 만들어 볼게요.

이미 사용할 프로젝트가 있다면 건너뛰셔도 좋습니다 :)

자바 18, 그래들 선택
아무런 의존성을 선택하지 않고 깨끗한 프로젝트로 만듭니다
프로젝트 빌드가 완료된 후 프로젝트 트리

자, 빈깡통 프로젝트 생성이 완료되었습니다.

2. 라이브러리 추가 

이제 구현 및 테스트에 필요한 라이브러리들을 추가해볼게요.

우선 현재 build.gradle 파일은 아래와 같이 되어있을거에요

plugins {
    id 'org.springframework.boot' version '2.7.3'
    id 'io.spring.dependency-management' version '1.0.13.RELEASE'
    id 'java'
}

group = 'com.example'
version = '0.0.1-SNAPSHOT'
sourceCompatibility = '18'

repositories {
    mavenCentral()
}

dependencies {
    implementation 'org.springframework.boot:spring-boot-starter'
    implementation 'org.springframework.boot:spring-boot-starter-web'
    testImplementation 'org.springframework.boot:spring-boot-starter-test'
}

tasks.named('test') {
    useJUnitPlatform()
}

저기에 아래 5개 라이브러리들을 추가해줍니다.

implementation 'org.ehcache:ehcache:3.10.1'
implementation 'org.springframework:spring-context-support:5.3.22'

implementation 'org.projectlombok:lombok:1.18.24'
annotationProcessor 'org.projectlombok:lombok:1.18.24'

implementation 'ch.qos.logback:logback-classic:1.2.11'

왜 저 라이브러리들이 필요한지 하나씩 볼게요.

implementation 'org.ehcache:ehcache:3.10.1' jcache 구현체인 ehcache 사용을 위함
implementation 'org.springframework:spring-context-support:5.3.22' 스프링캐시의 어노테이션을 사용하기 위함
implementation 'org.projectlombok:lombok:1.18.24'
annotationProcessor 'org.projectlombok:lombok:1.18.24'
lombok 어노테이션을 사용하기 위함
implementation 'ch.qos.logback:logback-classic:1.2.11' 로깅을 위함

이렇게 라이브러리를 추가한 뒤 캐시설정을 좀 해주도록 할게요

3. 캐시 설정

com.example.demo.config 패키지를 만든 뒤 아래와 같이 CacheConfig 클래스를 작성해줍니다.

package com.example.demo.config;

import org.springframework.cache.CacheManager;
import org.springframework.cache.annotation.EnableCaching;
import org.springframework.cache.jcache.JCacheCacheManager;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;

import javax.cache.Cache;
import javax.cache.Caching;
import javax.cache.configuration.MutableConfiguration;
import javax.cache.expiry.CreatedExpiryPolicy;
import javax.cache.expiry.Duration;
import javax.cache.spi.CachingProvider;
import java.util.concurrent.TimeUnit;

@EnableCaching
@Configuration
public class CacheConfig {

    private final CachingProvider cachingProvider = Caching.getCachingProvider();
    private final javax.cache.CacheManager cacheManager = cachingProvider.getCacheManager();

    @Bean
    public CacheManager cacheManager() {
        return new JCacheCacheManager(cacheManager);
    }

    @Bean
    public Cache<Integer, Integer> commonCache() {
        MutableConfiguration<Integer, Integer> configuration =
                new MutableConfiguration<Integer, Integer>()
                        .setTypes(Integer.class, Integer.class)
                        .setStoreByValue(false)
                        .setExpiryPolicyFactory(CreatedExpiryPolicy.factoryOf(new Duration(TimeUnit.SECONDS, 5)));
        return cacheManager.createCache("commonCache", configuration);
    }
}

위 내용을 간략히 살펴보면 cacheManager 빈을 하나 등록해주고 그 캐시매니저에 commonCache라는 이름의 캐시 빈을 하나 등록해주는 겁니다. 이 commonCache가 key, value 페어를 저장하는 하나의 서랍이라고 생각하시면되고요. 여기서는 키와 값의 타입이 모두 Integer 이고 만료정책은 생성시간을 기준으로 5초로 설정해주었습니다.

 

4. API 구현 및 테스트

이제 commonCache에 값을 저장하고 만료되기 전까지 캐시의 데이터를 사용하도록 서비스 클래스를 하나 만들어주겠습니다.

package com.example.demo.service;

import org.springframework.cache.annotation.Cacheable;
import org.springframework.stereotype.Service;

@Service
public class CacheService {

    @Cacheable(cacheNames = "commonCache", cacheManager = "cacheManager", key = "#code")
    public Integer getCachedValue(int code) {
        System.out.println("계산중....");
        // DB 조회 등의 로직...
        return (int) (Math.random() * 10);
    }
}

com.example.demo.service 패키지를 만들고 CacheService 클래스를 작성했습니다.

getCachedValue 메서드에 @Cacheable 어노테이션을 붙여주고 commonCache를 사용하고 cacheManager는 CacheConfig에 등록했던 cacheManager 이름을 적어주었습니다. 그리고 key로 파라미터로 전달받는 code 값을 사용하겠다고 선언해주었습니다. 만약 key로 어떤 객체의 멤버변수를 사용해야한다면 key = "#obj.employeeId" 와 같이 사용가능합니다. (공식문서 참고)

CacheService.getCachedValue 가 호출되면 code 값을 key로하여 return된 Integer 값을 commonCache에 저장하게되고 만료시간인 5초 이내에 동일한 key값(여기서는 code 파라미터 값)으로 메서드 호출이 발생할 경우 메서드 내부의 비즈니스 로직을 타지않고 바로 캐시에 저장되어있는 값을 반환합니다. 이를 확인하기위해 계산중.... 메시지를 출력하도록 했습니다.

 

마지막으로 위 서비스를 호출하는 테스트 API 를 만들어 줄게요.

com.example.demo.controller 패키지를 신규추가하고 TestController를 생성하겠습니다.

package com.example.demo.controller;

import com.example.demo.service.CacheService;
import lombok.RequiredArgsConstructor;
import lombok.extern.slf4j.Slf4j;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;

@Slf4j
@RestController
@RequestMapping("/test")
@RequiredArgsConstructor
public class TestController {

    private final CacheService cacheService;

    @GetMapping("/cache")
    public Integer getCachedValue(int code) {
        log.info("Request accepted for code {}", code);
        return cacheService.getCachedValue(code);
    }
}

API 호출이 들어올때마다 Request accepted for code X 로그가 출력되도록 하고, 캐시서비스의 메서드를 호출하도록 했습니다.

이제 DemoApplication을 실행하고 API를 호출해볼게요.

2022-09-14 12:32:59.783  INFO 47720 --- [           main] com.example.demo.DemoApplication         : Started DemoApplication in 0.778 seconds (JVM running for 0.997)
2022-09-14 12:33:06.871  INFO 47720 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2022-09-14 12:33:06.871  INFO 47720 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2022-09-14 12:33:06.872  INFO 47720 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 1 ms
2022-09-14 12:33:06.882  INFO 47720 --- [nio-8080-exec-1] c.e.demo.controller.TestController       : Request accepted for code 1
계산중....
2022-09-14 12:33:08.270  INFO 47720 --- [nio-8080-exec-2] c.e.demo.controller.TestController       : Request accepted for code 1
2022-09-14 12:33:09.186  INFO 47720 --- [nio-8080-exec-3] c.e.demo.controller.TestController       : Request accepted for code 1
2022-09-14 12:33:10.017  INFO 47720 --- [nio-8080-exec-4] c.e.demo.controller.TestController       : Request accepted for code 1
2022-09-14 12:33:10.880  INFO 47720 --- [nio-8080-exec-5] c.e.demo.controller.TestController       : Request accepted for code 1
2022-09-14 12:33:11.764  INFO 47720 --- [nio-8080-exec-6] c.e.demo.controller.TestController       : Request accepted for code 1
2022-09-14 12:33:12.631  INFO 47720 --- [nio-8080-exec-7] c.e.demo.controller.TestController       : Request accepted for code 1
계산중....
2022-09-14 12:33:13.538  INFO 47720 --- [nio-8080-exec-8] c.e.demo.controller.TestController       : Request accepted for code 1
2022-09-14 12:33:14.408  INFO 47720 --- [nio-8080-exec-9] c.e.demo.controller.TestController       : Request accepted for code 1

호출은 모두 code값 1을 넣어서 하였고, 최초 호출을 12:33:06.882 에 하면서 서비스 내부로직을 실행하여 값을 반환하였습니다. (계산중.... 출력으로 확인)

이후 12:33:11.764 까지는 계산중.... 이 출력되지 않은 것으로 보아 캐싱되어있는 값을 그대로 응답한걸로 볼 수 있습니다.

5초가 지난 12:33:12.631 에 들어온 호출건은 계산중.... 이 출력된걸로 보아 응답값에 변동이 발생했을 것으로 추측됩니다. (랜덤값으로 응답하는 서비스니 응답값에 변동이 없을 수도 있죠)

여기서 중요한 것은 응답값에 변동이 있느냐가 아니라 캐시되어있는 데이터가 만료되기 전까지 메서드 내부로직을 실행하지 않고 캐시에서 조회된 데이터를 리턴해준다는 점입니다.

 

이상으로 5분만에 스프링캐시와 ehcache를 이용하여 캐시를 구현하는 방법에 대해 알아보았습니다.

 

읽어주셔서 감사합니다~  🙇

💻 Programming

[AWS] redis-cli 를 이용한 elasticache 데이터 조회

아직 redis-cli 설치가 안되어있다면 redis-cli 설치를 참고해주세요

 

1) 전체 key 개수 조회

redis.0001.apn.cache..amazonaws.com:6379> info keyspace
# Keyspace
db0:keys=23976,expires=2023,avg_ttl=125758665

2) 전체 key 목록 조회

redis.0001.apn.cache..amazonaws.com:6379> keys *
1) "EmployeeName:Tom Johnson"
2) "ZipCode:67410"
3) "EmployeeName:Tom Hanks"
4) "EmployeeName:Tom Thumb"
5) "ZipCode:15206"

 

keys 명령어 사용시 주의점: 운영환경에서는 신중히 사용할 것 !!

Warning: consider KEYS as a command that should only be used in production environments with extreme care. It may ruin performance when it is executed against large databases. This command is intended for debugging and special operations, such as changing your keyspace layout. Don't use KEYS in your regular application code. If you're looking for a way to find keys in a subset of your keyspace, consider using SCAN or sets.

3) value 타입 확인 (value 타입에 따라 조회 명령어가 다름)

redis.0001.apn.cache..amazonaws.com:6379> get "EmployeeName:Tom Johnson"
(error) WRONGTYPE Operation against a key holding the wrong kind of value

redis.0001.apn.cache..amazonaws.com:6379> type "EmployeeName:Tom Johnson"

hash

4) 타입 유형별 조회 command

string : get <key>
hash : hgetall <key>
lists : lrange <key> <start> <end>
sets :  smembers <key>
sorted sets : ZRANGEBYSCORE <key> <min> <max>

데이터 타입에 따른 더 다양한 명령어는 Redis 공식문서 참고

Redis 모든 명령어 목록

5) 특정 key에 대한 value 조회 (hash타입 데이터)

redis.0001.apn.cache..amazonaws.com:6379> hgetall "EmployeeName:Tom Johnson"
1) "_class"
2) "com.mycompany.employee.EmployeeName"
3) "name"
4) "Tom Johnson"
5) "id"
6) "2267849"

redis.0001.apn.cache..amazonaws.com:6379> hget "EmployeeName:Tom Johnson" name

"Tom Johnson"

sudo yum install -y gcc 
wget http://download.redis.io/redis-stable.tar.gz && tar xvzf redis-stable.tar.gz && cd redis-stable && make
sudo cp src/redis-cli /usr/bin
redis-cli -h {redis-endpoint-address}

1) EC2에 build를 위한 gcc 설치

$ sudo yum install -y gcc 

2) redis stable 버전 다운로드 및 빌드

$ wget http://download.redis.io/redis-stable.tar.gz && tar xvzf redis-stable.tar.gz && cd redis-stable && make

3) redis-cli 로 접속해보기 (기본포트 사용시 포트정보 필요없음)

$ ./src/redis-cli -h {레디스엔드포인트주소} -p {포트번호}

4) 사용의 편의성을 위해 usr/bin 디렉토리에 redis-cli 명령어 복사해놓기

$ sudo cp src/redis-cli /usr/bin

💻 Programming

[AWS] SQS와 Lambda를 이용하여 DLQ 처리하기

안녕하세요, 오랜만에 글을 씁니다.

 

오늘 공유드리는 내용은 분산시스템에서 DLQ 처리하는 방법에 대한 것입니다.

제가 관리하는 시스템 중 하나가 주로 카프카 메시지를 컨숨하여 처리하는 일을 하는 시스템입니다.

여러 개의 인스턴스가 존재하고 모두 동일한 소스코드가 배포되어있죠.

소스코드에는 JPA를 이용한 CRUD 로직이 들어있습니다.

 

문제가 없던 시스템인데 관련부서에서 파티션 개수를 늘리면서 문제가 생겼습니다.

단순히 파티션 개수가 늘어난게 문제가 아니라 그쪽에서 보내는 카프카 메시지의 특성과도 관련이 있었죠.

파티션마다 서로 다른 인스턴스에서 처리하지만 각 메시지에는 서로 중복된 데이터의 내용이 들어가 있는 형태였고 (이건 뭐 제가 어찌 할 수 없는 것이죠), 동일한 데이터를 서로 다른 인스턴스에서 JPA를 이용해서 처리하다가 드물게 ObjectOptimisticLockingFailureException 이 발생하기 시작했습니다. 

예를들어 인스턴스 1번에서 {A, B} 라는 메시지를 처리할 때 인스턴스 2번에서 {A,C}, 3번 인스턴스에서 {A,D} 메시지를 처리하면서 A 데이터를 3대의 인스턴스에서 동시에 처리하려고 한거죠. 세 개의 메시지는 서로 다른 데이터도 들고있으므로 무조건 처리를 해줘야 하는 것들이었습니다.

이걸 어떻게 할 까 고민하다가 SQS를 DLQ를 이용하여 Lambda 와 연결시켜 일정 시간이 지난 뒤에 수동동기화 API를 호출하도록 구성하기로 했습니다.

이렇게 한 이유는 가장 빠른시간에 추가적인 소스구현 없이 효과적으로 목적을 달성할 수 있었기 때문입니다.

만약 DLQ로 들어오는 메시지가 많아진다면 소스코드를 구현하는게 비용측면에선 더 효율적입니다.

인스턴스는 어차피 떠있어야 하는거고 람다를 제거할 수 있으니 람다에서 발생하는 비용이 줄어듭니다.

하지만 소스코드 구현시 고려해야할 점이 있죠. 인스턴스가 여러개 떠있지만 하나의 인스턴스에서만 DLQ의 메시지를 처리하도록 해야한다는 거죠. 그렇지 않으면 또 처리에 실패하는 경우가 발생할 테니까요. 그리고 모든 인스턴스에 동일한 소스코드가 배포되어야 하는데 하나의 인스턴스에서만 실행이 되도록 하려면 또 이런저런 코드를 작성해야 하다보니 람다를 이용하기로 했습니다.

 

아무튼, SQS를 DLQ로 이용하고, Lambda 함수를 연결시켜 일정 시간뒤에 수동API를 호출하여 실패했던 메시지에 대한 정보를 읽어와서 처리하도록 했습니다.

SQS Lambda Trigger 설정

이렇게 설정해놓으면 SQS 메시지가 발행될 때마다 Lambda 함수를 실행하는데 Lambda 함수에서는 API를 호출하도록 구성했습니다. 람다 트리거에 대한 내용을 AWS에서는 다음과 같이 설명하고 있습니다.

You can configure your Amazon SQS queue to trigger an AWS Lambda function when new messages arrive in the queue.
Your queue and Lambda function must be in the same AWS Region.
A Lambda function can use at most one queue as an event source. You can use the same queue with multiple Lambda functions.
You can't associate an encrypted queue that uses the AWS-managed CMK for Amazon SQS with a Lambda function in a different AWS account.

저의 경우에는 필요없긴하지만, 하나의 SQS에 여러개의 람다함수를 연결하여 사용할 수 있다는 점이 좋아보이네요.

 

자, 그리고 SQS와 연결한 Lambda 함수는 다음과 같습니다.

import logging
import json
from urllib.request import Request, urlopen
from urllib.error import URLError, HTTPError

logger = logging.getLogger()
logger.setLevel(logging.INFO)

API_URL = "https://company.com/employees/{}"

def lambda_handler(event, context):

    message = json.loads(event['Records'][0]['body'])
    
    url = API_URL.format(message['employeeId'])
    headers = {'Content-type':'application/json'}
    
    req = Request(url, headers=headers, data=b'', method='PUT')
    
    try:
        response = urlopen(req)
        return response.getcode()
    except HTTPError as e:
        logger.error("Request failed: %d %s, sqsBody:%s", e.code, e.reason, message)
        return e.code
    except URLError as e:
        logger.error("Server connection failed: %s, sqsBody:%s", e.reason, message)
    return None

Python은 공부한적 없으나, 자바는 컴파일언어라 코드를 직접 AWS콘솔에서 작성할 수 없어서 python으로 작성했습니다.

 

내용은 별거 없고 event에 SQS 메시지의 내용이 들어오기 때문에 event에서 메시지의 body 내용을 추출하여 message 변수에 넣고 이것을 API 호출할 때 사용한것이 다입니다. 여기서는 employeeId 값이 SQS 메시지에 {"employeeId":1234} 형태로 들어있었다면, 저기서 1234 값을 추출하여 api 호출할때 path variable로 넣어서 https://company.com/employees/1234 를 호출하도록 한거죠. 

 

위 코드상에선 에러가 발생하면 그냥 로깅하거나 에러코드 리턴하도록 해놓았는데, 에러건이 많이 발생한다면 슬랙알람을 보내도록 하는 것도 좋을 것 같습니다.

 

 

이상으로 SQS와 Lambda를 이용한 분산처리시스템에서의 DLQ 처리에 대한 기록을 마칩니다.

사실 이걸 git 명령어로 확인할 일이 얼마나 있겠냐마는 다음에 혹시라도 또 쓸일이 있을까봐 기록용으로 남깁니다.

 

git shortlog -sne --since="01 Apr 2022" --before="01 May 2022" --no-merges

위 명령어를 이용하면 22년 4월 1일부터 22년 5월 1일 전까지, 즉, 4월 한달동안 merge 커밋을 제외한 실질적인 개발작업의 커밋건수를 확인할 수 있습니다.

결과는 아래와 같이 출력됩니다.

 53  홍길동 <gildong.hong@company.com>
 49  김철수 <cheolsoo.kim@company.com>
 31  임꺽정 <kj.lim@company.com>