오랜만에 작성하는 개발일지이다. 9월은 지난번 개발한 투표/설문 조사의 성능개선을 했고, 10월은 새로운 프로젝트에 들어갔다.
9월에 마무리된 개발건이 배포가 밀려 10월까지 밀리면서 엄청 바쁜 10월 한 달을 보낸 것 같다.
10월 시작하는 프로젝트는 완전 백지상태에서 시작하는 작업이다 보니 새로운 경험을 생각보다 많이 했는데 해당 부분에 대해 기록으로 남기고자 한다.
유저인증
유저의 인증 경우 토큰방식을 선택했는데, 이 토큰을 jwt가 아닌 암호화 알고리즘을 이용해서 작성하게 되었다.
지난번 작성한 포스팅이 이 암호화 및 해쉬에 대해 작성을 했다.
아무튼 로그인에 대해 암호화는 지난번 포스팅에 작성한 것처럼 작성하였다.
토큰의 만료기한 또한 디비에서 관리하게 되면서 매번 만료기한을 업데이트시켜주어야 했다.
미들웨어를 사용해서 해당 비즈니스 문제를 해결했다.
미들웨어란 요청,응답이 서비스 라우팅에 닿기 전 또는 닿은 후 응답을 각각 가로챌 수 있는데 가로채서 토큰의 유무를 검증하고 토큰의 파싱값을 컨택스트에 넣어주는 방법으로 작성했다.
여기서 컨택스트란 에코-프레임워크를 비롯해 고에서는 http 요청을 하나의 고 루틴으로 해결한다. 이렇게 고 루틴으로 할당되면 해당 고 루틴을 이용해 request와 response를 처리한다.
이에 따라 각 레이어를 넘나들면서 context 를 들고 이동하게 되는데 이는 처음 루틴을 생성했을 때부터 데이터들을 가지고 레이어들을 넘나 든다. 그 외에도 context를 이용해 deadline, cancel 등 고 루틴의 핸들링을 쉽게 다루는 방법이 존재하니 검색해서 확인하자.
func Authorization(key,tokenURL string) echo.MiddlewareFunc {
return func(next echo.HandlerFunc) echo.handlerFunc {
return func(c echo.Context) error {
headerToken := c.Requset().Header.Get("Authorization")
if 특정 URL 을 가지고 있다면? {
URL 요청 토큰연장
}
if tkn,err := 토큰 parse; err != nil {
return http.StatusUnauthorized 요청
}else{
c.Set("token",tkn)
return next(c)
}
}
}
}미들웨어를 반환해 주는 함수를 작성해 준다면 미들웨어의 적용이 가능하다.
작성된 미들웨어는 아래와 같이 적용가능하다.
func run() error {
e := echo.New()
e.Use(atask_middleware.Authorization("key","tokenURL"))
routing(e)
return e.Start("포트")
}이렇게 작성된 에코는 라우팅되어 있는 URL 함수가 실행되기 전 미들웨어를 먼저 타게 된다.
Request, Response dump
입출 하는 모든 Request, Response에 대해서 로그를 남기고자 했다.
위에서 언급한 미들웨어의 특성 중 Request Response 모든 시점에 캐치가 가능하다고 작성했다.
해당 특성을 이용하면 로그에 대해 손쉽게 작성할 수 있다.
type dumpResponseWriter struct {
io.Writer
http.ResponseWriter
}
func (w *dumpResponseWriter) Write(b []byte) (int, error) {
return w.Writer.Write(b)
}
func LoggerDump() echo.MiddlewareFunc {
return func(next echo.HandlerFunc) echo.HandlerFunc {
return func(c echo.Context) error {
// request 요청
reqBody := []byte{}
if c.Request().Body != nil { // Read
reqBody, _ = io.ReadAll(c.Request().Body)
}
c.Request().Body = io.NopCloser(bytes.NewBuffer(reqBody))
// response 요청
resBody := new(bytes.Buffer)
mw := io.MultiWriter(c.Response().Writer, resBody)
writer := &dumpResponseWriter{Writer: mw, ResponseWriter: c.Response().Writer}
c.Response().Writer = writer
if err := next(c); err != nil {
return err
}
dump(c, reqBody, resBody.Bytes())
return nil
}
}
}
Request부터 확인해 보면 바디를 읽어서 선언한 reqBody에 읽어온 데이터값을 할당하고,
다시 c.Request(). Body에 값을 reqBody로부터 읽어온 값을 할당해 준다.
왜 이런 2번의 작업이 필요하냐면 c.Reqeust(). Body는 일회성 스트림이다.
다시 말해 한번 읽으면 다시 읽을 수 없다는 것을 의미하기 때문에 다시 할당해 주는 부분이 필요하다.
(그렇지 않다면 실제 라우팅의 함수에서 리퀘스트 바인딩에 어떠한 값도 가져올수없다...)
Response의 경우 response writer를 위에 작성한 커스텀타입의 Writer로 덮어주는 방법이다.
multiWriter를 이용해 바이트 버퍼와, response 응답값 모두에 응답값을 작성하게 된다.
{"level":"info","time":"2023-10-31T14:53:26+09:00","caller":"hsad-poc/atask_common/atask_middleware/logger.go:76","message":"
[REQUEST][METHOD:POST][URI:/user/api/v1.0/login][USER:] body : {"email":"","password":""}
[RESPONSE][STATUS:200][Latency:42.674µs] body: {"code":200,"data":{"access_token":"","email":"","grade":"","member_id":,"username":""},"msg":"SUCCESS"}"}결과적으로 위와 같은 로그라인을 작성했다.
문제발생
다음날 출근해 보니 총 4개의 프로세스가 떠있어야 했는데 특정 프로세스 한 개가 죽어있었다...
로그를 확인해 보니 1개의 프로세스에서는 이미지 업로드가 포함되어 있어 멀티파트 폼 데이터를 사용하게 되는데...
해당 이미지의 바이트 코드를 전부 로그에 작성해 버리는 것이 아닌가....
func parseMultiPartForm(c echo.Context) []byte {
if err := c.Request().ParseMultipartForm(maxMemory); err != nil {
log.Error().Err(err).Msgf("fail to parsing multi part form data")
}
m := make(map[string]interface{})
for key, value := range c.Request().Form {
if key != "file" {
m[key] = value
}
}
data, err := json.Marshal(m)
if err != nil {
log.Error().Err(err).Msgf("fail to marshal data %+v", data)
data = []byte{}
}
return data
}멀티파트를 포함한 요청인경우 분기를 나누고 위와 같은 방법을 적용했다.
에코에서 parse를 지원해 줘서 다행이지.. 아니었으면 한 삽 펐을 것으로 보인다.
map을 이용해 file을 제외한 모든 경우를 담아 json으로 엔코딩 해서 바이트로 반환해 주었다.
zerolog
지난 프로젝트에서 logurs 라이브러리를 이용해 로그를 작성했다.
하나 해당 로그라이브러리로 인해 tps측정에 문제가 되는 것을 확인하고, 이번 신규프로젝트에서는 zerolog를 적용하기로 했다.
middleware 쪽을 담당하고 있다 보니 로그도 자연스레 나의 파트가 되어버렸다.
목적
1. 콘솔 로그 작성
2. 파일 로그 작성(일별로)
1차시도 Hook을 이용한 방법 (실패)
zerolog 홈페이지에 Hook에 대한설명이 짤막하게 남아있는데, 해당 hook을 이용하면 매번 로그가 호출되어 콘솔에 적힐 때마다.
파일에 남긴다 라는 생각을 했다.
type FileWriter struct {
log chan byte
cur time.Time
file *os.File
}
func (f FileWriter) Run(e *zerolog.Event, level zerolog.Level, message string) {
// 날짜 비교 해서 날짜가 지났으면 카피 후 새파일 생성
// 파일 열고 없으면 만들고
// 파일 에 message를 작성한다.
}이렇게 작성했더니 이게 웬걸 message 에는 내가 원하는 정보들이 담겨있지 않았다....
어디서 로그가호출 되었고, 타임라인이 어떤지 는 없고 단순 로그에 넘긴 메세지만 저 message 함수인자 값으로 넘어온다...
하루종일 zerolog hook에 대해서 찾아봤으나 원하는 정보를 찾기 힘들었다.
2차시도 Multiwriter를 이용한 방법
zerolog document를 처음부터 정독했다. 거의 막바지에 Multiple Log Output이라는 섹션이 있는데 이를 이용하면 로그를 여러 방면으로 남길 수 있게 된다.
제공하는 함수로는 MultiLevelWriter이고, io.Writer 인터페이스만 만족하면 된다.
바로 인터페이스 구현체를 작성했다.
func New(path, fileName string, logLevel zerolog.Level) zerolog.Logger {
console := zerolog.ConsoleWriter{Out: os.Stderr}
multi := zerolog.MultiLevelWriter(console, NewFileWriter(path, fileName))
zerolog.CallerMarshalFunc = func(pc uintptr, file string, line int) string {
return file + ":" + strconv.Itoa(line)
}
return zerolog.New(multi).Level(logLevel).With().Timestamp().Caller().Logger()
}콘솔은 콘솔라인에 남기기 위한 writer, NewFileWriter는 file에 남기기 위한 writer 가 되겠다.
CallerMarshalFunc 같은 경우는 로그의 호출이 무슨 파일, 몇 번째 줄에서 발생되어 어떤 형식으로 작성하겠는가? 를 설정해 주는 부분이다.
type FileWriter struct{
log chan []byte
file *os.File
cur time.Time
path string
}
func prettier(s string) []byte {
// \문자제거, 라인분할
}
func (f *FileWriter) Write(p []byte) (n int,err error) {
// log <- 채널로 메세지 전송
}
func (f *FileWriter) WriteLog(msg []byte) (int,error){
// 인터페이스 구현함수
return f.file.Write(msg)
}
func(f *FileWriter) IsRotate(now time.Time) bool {
// 마지막 파일 수정일 기준으로 하루가 지났는가?
}
func(f *FileWriter) RotateFile(now time.Time)error{
// 현재 파일의 이름을 변경
// 현재 시간 변경
// 현재 파일 새로운 파일로 변경
}
func NewFileWriter(path, name string) *FileWriter{
// 파일 셋팅
// 시간 세팅
go func() {
for v := range 로그채널 {
//v 값을 writeLog 함수 호출
}
}
}우선 타입을 살펴보면 log의 값을 받기 위해 채널을 설정했다. 버퍼링 채널을 위해 1024를 설정했다.
비동기 채널링을 설정한 이유는 로그의 중복된 값 혹은 로그의 씹힘을(동시성)문제를 방지하기 위해 채널링을 생성했다.
아무래도 채널을 구성하게되면 큐의 자료형태로 들어가게 되고 1024의 로그만큼 계속 비동기적으로 로그를 작성하게 된다고 생각되어 채널을 선택했다.
지난번 고의 동시성 프로그래밍 책에서도 뮤텍스보다는 채널을이용해서 작성할 것을 권장했는데 이렇게 적용하게 될 줄을 몰랐다..
또한 파일의 OS 값을 받아오면 해당 파일의 마지막 업데이트 값을 받아올 수 있다....
해당 사실을 몰라 마지막 로그의 인덱스로부터 1024바이트씩 읽어 날짜 값을 가져와 파싱 해서 비교하는 로직을 작성했는데...
엄청난 삽질이 아닐 수가 없다.
해당 로그의 인터페이스를 구현 하면서 지난번 읽었던 UltimateGo 에서 왜 인터페이스의 함수의 변수 사용에 대해 강조했는지 조금이나마 이해가 간다.
함수의 변수를 인터페이스로 받으니깐 다형성의 적용이 무궁무진하다...
다만 이런생각이 든다. 고였으니깐.. 인터페이스의 구현이 생각보다 쉬웠의깐
나만의 커스텀 함수를 작성해서 인터페이스의 구현체를 작성하지 않았을까? 라는 생각이 든다.
과연 스프링 부트였다면 이 인터페이스를 구현해서 커스텀하게 작성했을까? 라는 의문이 드는 부분이었다...
검색을 통해 내가 구현하고자 하는 라이브러리에 대해 찾고 해당 라이브러리를 추가해서 사용하지 않을까 싶다...
3. 일별 로그 기록 -> 용량별 로그기록
Git Action, Kubernetes, istio 등의 DevOps를 팀장님이 설정하고 나니, 클라우드워치(aws 인프라를 사용한다.) 또한 적용하게 되는 것이 아닌가. 이러다 보니, 쿠버네티스의 각 파즈 별로 들어가서 로그를 확인할 일이 줄어들고, 이에 따라 로그의 작성을 일단위가 아닌 용량단위 그리고 백업은 대략 3~5개 파일로 구성하자는 의견이 팀회의를 통해 나왔고...
해당 로직을 구성하기 위해 lumberjack 이라는 라이브러리를 사용했다.
lumberjack 라이브러리는 로그를 기록하고자 하는 폴더의 로그 파일을 감시하고, 로그의 용량을 판단해 새로운 로그 파일을 작성할지 아닐지에 대해 구현해 놓은 간단한 라이브러리였다.
지난번 일별구현은 왜 커스텀하게 하고 이거는 라이브러리를 사용했는가에 대해 의문이 생길 수 있다.
지난번 일별 로그기록을 할 때 당연히 해당 라이브러리의 기능을 확인했으나, 팀에서 추구하는 바와 달라 포기했던 기억이 있어 팀의 비즈니스 로직이 변경되자마자 lumberjack 라이브러리를 적용했다.
이렇게 미들웨어부터 msa의 공통 로그까지 작성해 봤다. 물론 api 핸들러를 작성한 것은 당연한 것이고...
처음 시작할 때 말했다 것처럼 이번 프로젝트의 초기 뼈대를 잡는데 정말 많은 시간을 할애했다.
내가 분명 UltimateGo, EffectiveGo에서 본 naming convention, package convention 과는 많이 달랐다 그러나 팀이 추구하는 방향에 따라 상당 부분 달라질 수 있다.
이러한 자율성이 고가 가진 힘이자, 위험한 부분이라고 생각한다.
프로젝트 시작과 동시에 이러한 컨벤션을 작성하지 않은 것이 참 후회된다.
사수님과 내가 작성한 코드를 보면 코드의 통일성이 없이 각 프로세스 별로 각자의 주관이 상당히 뚜렷하다.
DVT (Testing)가 성공적으로 종료되었지 만 개인적으로 이번 프로젝트는 10점 만점에 6점짜리 프로젝트인 것 같다.
지난번 투표/설문조사를 통해 가독성에 대해 상당히 많은 코드리뷰를 받았었다... 그렇기 때문에 ultimateGo, EffectiveGo, GoogleGO CodeConvention, BankSalad Go BLog, Buzvill 블로그 등 상당히 많은 블로그를 보며 고의 표준 레이아웃, 패키지 컨벤션 등 을 확인했지만, 오히려 해당 컨벤션을 지키면서 작성했던 것이 팀의 코드 히스토리상 어긋난다는 이유로 전부 변경 했어야 했다.
항상 코드리뷰를 보면 서비스의 로직에 대한 부분보다 이러한 컨벤션에 대한 리뷰가 많았다...
내가 보고 배운 표준 컨벤션과는 다른 것을 적용하다 보니, 이러한 컨벤션에 대한 정의를 미리 내려야 하지 않을까 싶다.
이렇게 제공되는 자율성이 고가 가진 장점이자 단점이라고 생각한다.
이러한 부분을 수정하면서 느낀 것은 왜 코드컨벤션이 필요한가? 에 대한 명확한 이유를 납득했다.