Spring Boot Access Log 요청 호출 수, 응답시간 또는 사이즈 순으로 통계 (Linux Shell Script 활용)

여러 API URI 혹은 페이지를 가지고 있는 스프링부트 애플리케이션의 액세스 로그 (Access Log)를 통해 시간당 혹은 분당 URL별 호출 수 (호출량)를 통계 낸다거나, 특정 시간 대 응답 시간이 가장 긴 호출 혹은 응답 사이즈가 큰 호출의 랭킹을 조사하는 등 간단하게 통계를 내야 하는 경우가 생겨서 정리를 해보려고 합니다.

다른 모니터링 툴이나 다른 방법이 있겠지만 여기서는 Embedded Tomcat을 활용한 간단한 Spring Boot 어플리케이션의 경우 Tomcat Access Log와 서버의 리눅스 쉘 스크립트를 통해서 아주 간략히 통계를 내는 방법을 정리해보도록 하겠습니다.

 

Access 로그 예시

먼저 위와 같은 여러 URL과 다양한 파라미터를 가진 Rest API 스프링부트 애플리케이션의 내장 Tomcat Access Log가 있다고 가정을 해보겠습니다. Access Log의 패턴은 기본 Default 패턴에 처리시간이 포함된 '%h %l %u %t "%r" %s %b %D'와 같이 정의를 하였습니다. 스프링부트 application.yml 파일의 Tomcat Access Log 파일 설정은 아래와 같이 간단하게 작성하였습니다. (참고 : https://kim-oriental.tistory.com/43)

server:
  tomcat:
    accesslog:
      enabled: true
      pattern: '%h %l %u %t %r %s %b %D'

 

 

URL당 호출 수 통계 (1분 단위 집계)

먼저 특정 한 시간 (예: 12-05일 00시) 동안 호출된 URL의 수를 1분 단위로 집계를 하려고 합니다. 예를 들어 /get/member라는 URL이 0시 0분, 1분, 2분, 3분... 에 몇 번이 호출이 되었는지 카운트를 한다고 가정을 하겠습니다.

단계적으로 간략히 설명을 하면, 먼저 리눅스에서 cat 명령을 통해서 Access Log를 조회하여, 0시(24시)의 Access Log만 grep 되도록 아래와 같이 커맨드를 작성을 합니다.

cat access_log.2022-12-05.log | grep "2022:00"

 

그런 다음 awk과 print 명령을 통해서 내가 카운트를 할 텍스트만 남겨놀 수 있도록 가공을 합니다.

cat access_log.2022-12-05.log | grep "2022:00" | awk '{print $4,$7}' | awk -F ":" '{print $2,$3,$4}' | awk -F " " '{print $1,$2,$4}'

 

위와 같이 스크립트를 날리면, 아래와 같이 "시간 / 분 / URL"로 필요한 정보만 남아 Access Log가 조회되는 것을 확인할 수 있습니다. 

커맨드 결과

마지막으로 파라미터도 필요없으므로 "?"로 Split를 하고, 반복문과 Sort를 통해 카운트를 해서 최종 "시간 / 분 / URL / 호출 수" 형태로 집계를 내도록 하였습니다.

cat access_log.2022-12-05.log | grep "2022:00" | awk '{print $4,$7}' | awk -F ":" '{print $2,$3,$4}' | awk -F " " '{print $1,$2,$4}' | awk -F "?" '{arr[$1]+=1} END {for(i in arr) {print i " " arr[i]}}' | sort

 

시간 / 분 / URL / 호출 수

최종적으로 위와 같이 0시 0분, 1분동안 get/member라는 URL이 3번 호출되었다는 것을 확인할 수 있습니다.

 

시간별 URL 호출 수 통계

위의 톰캣 엑세스 로그와 쉘 스크립트를 활용하여, 00:00~01:00시까지 1시간 단위로 시간별로 URL이 몇 건이 호출이 되었는지 집계하여 통계도 낼 수 있습니다. 유사하게 시간과 URL만 남도록 로그를 정리하여 최종적으로 시간당 몇 건이 호출되었는지 카운트를 합니다. 아래의 커맨드를 날리면, 하기 이미지처럼 "시간 / URL / 몇 건 호출 되었는지 카운트"로 조회도는 것을 볼 수 있습니다. 호출 수가 많은 로그의 경우 시간당 혹은 일별 등 큰 단위로 집계를 할 경우 서버 리소스에 무리를 줄 수 도 있을 것 같습니다.

cat access_log.2022-12-05.log | awk '{print $4,$7}' | awk -F ":" '{print $2,$4}' | awk -F " " '{print $1,$3}' | awk -F "?" '{arr[$1]+=1} END {for(i in arr) {print i " " arr[i]}}' | sort

 

시간 / URL / 호출 수

 

응답 시간이 긴 혹은 응답 사이즈가 큰 호출 로그 순위

마지막으로, 일별 / 시간별 / 분별로 응답 시간이 가장 길었던, 혹은 응답 사이즈가 가장 컸던 호출 Access 로그의 순위를  Sort 명령을 통해서 통계를 낼 수 있습니다.

위의 Access 로그에서 0시0분에 호출 중에서 처리시간이 길었던 호출 5개를 조회한다고 가정을 하겠습니다. 로그를 공백으로 Split을 하였을 때, 11번째가 요청 처리시간이므로 -rnsk 11 옵션으로 Sort를 하고 head -5를 통해 상위 5개만 조회하도록 하였습니다. 만약 응답이 큰 요청에 대한 순위를 구하려면 -rnsk 10으로 변경을 하면 조회할 수 있습니다.

cat access_log.2022-12-05.log | grep "2022:00:00" | sort -rnsk 11 | head -5

 

0시 0분동안 처리시간이 가장 길었던 5개 호출

 

위와 같이 리눅스의 쉘스크립트를 이용해서 Spring Boot Tomcat의 Access Log를 간단하게 분석에 필요한 전처리 통계 데이터 정도를 얻을 수 있었습니다. 사실 지속적으로 요청 데이터를 수집하고 모니터링하기 위해서는 다양한 툴들이 있는데, 간단하게 이벤트성으로 이슈에 대응을 하는 용도 정도로 활용은 가능할 것 같습니다.