전에는 Debug.Log로 로그를 남겼는데 Custom Logger를 구현해 커스텀 로그를 활용하는 방식으로 수정했다. 해당 방식으로 수정한 이유와 방법을 간략히 정리해 보겠다.
1. 로그를 남기는 이유 및 이점
2. 기존 Debug.Log 방식의 문제점
3. Custom Logger 기본 구조
4. Custom Logger 구현 및 수정
5. 작업한 코드 적용
6. 후기
7. 출처
1. 로그를 남기는 이유 및 이점
우선, 로그를 남기는 이유에 대해 고민해보자.
로그를 남기는 이유는 히스토리를 기록해서 해당 이벤트의 원인, 과정, 결과를 확인하게 만든다.
근본적으로 다양한 상황에서 발생할 수 있는 에러 및 버그를 명시적으로 확인 및 원인 분석을 용이하게 하기 위함이다.
로그를 통해 얻을 수 있는 결과는 아래와 같다.
1) 로직 시각화
= 유니티 에디터를 통해 결과값만 확인하는 것이 아닌 로직의 과정을 확인해 이벤트에 관련된 로직의 프로세스를 빠르게 파악할 수 있다.
2) 기기에 상관없이 버그 및 에러 확인 용이
= 개발환경이 아닌 콘솔, 모바일, 다른 PC 등에서도 로그를 확인해 특정 이벤트를 분석할 수 있다.
3) 유니티 라이프사이클 순서 확인 가능
= Start(), Update() 순서 꼬임으로 인해 발생하는 문제(매니저가 초기화되기 전 플레이어가 데이터 요구) 등을 확인 후 해결할 수 있다.
4) 게임 이벤트 결과에 대한 원인 파악 용이
= 플레이어 체력이 0이 된 것과 같이 게임 내 발생하는 이벤트 결과에 대한 과정, 원인을 분석할 때 로그를 통해 히스토리를 확인해 해결가능하다.
2. 기존 Debug.Log 방식의 문제점
기존에는 Debug.Log를 원하는 곳에 작성하고, 이를 배포할 때 빌드에서 지우거나 필요한 것만 남기는 방식이었다.
이 방식의 문제점에 대해 알아보자.
1) CPU 사용량 증가 및 GC 발생
Debug.Log는 해당 로그가 발생한 위치를 출력하기 위해 현재 실행중인 모든 호출 스택(Stack Trace) 정보를 수집한다.
=> 메인 스레드에서 진행되기 때문에 프레임 드랍의 주 원인이 된다.
Debug.Log에 문자열 또는 다른 값 타입을 출력할 경우를 살펴보자.
= string은 매번 새로운 문자열 인스턴스를 생성하고, int같은 값 타입은 로그에서 object로 변환되는 박싱(boxing)이 발생하여 힙 메모리를 할당한다.
=> GC가 자주 실행되게 만들어 게임이 순간적으로 멈추는 히컵(Hiccup) 현상을 유발한다.
= 로그는 콘솔 뿐만 아니라 디바이스의 파일 시스템에도 기록되어 I/O 병목이 발생할 수 있다.
2) 불필요한 빌드 파일 용량 증가
Debug.Log가 참조하는 문자열이나 객체들은 컴파일러가 사용중이라고 판단하여 빌드에서 제거되지 않아 앱 용량이 증가된다.
3) 멀티 스레드 이슈
Unity의 Debug API는 기본적으로 메인 스레드 친화적이다.
=> 멀티 스레드 환경에서 빈번하게 호출하면 Lock 경합이 발생하거나 스레드 안전성 문제가 발생할 수 있다.
3. Custom Logger 기본 구조
Custom Logger에 필요한 기본 조건은 아래와 같다.
1) 배포 빌드 시 로그 정리 용이 및 성능 최적화
= [Conditional]을 추가해 컴파일 단계에서 해당 함수의 호출을 제외시켜 오버헤드를 0으로 만든다.
= 게임이 출시될 때 개발용 로그 제외시키기 용이하다.
2) 로그 분류
= 기본 로그, 경고성 로그, 에러용 로그를 나눠서 적용할 수 있도록 구현한다.
3) Logger을 통한 중앙 집중 관리 용이
= 원하는 지점에 로그를 추가할 때 Logger 내 함수를 적용하도록 한다.
= 수정 및 개선이 필요할 때 일괄적으로 적용되어야 한다.
기본 뼈대는 아래와 같다.
using UnityEngine;
using System.Collections.Generic;
using System.Collections;
using System.Diagnostics;
public static class Logger
{
[Conditional("DEV_VER")]
public static void Log(string msg)
{
UnityEngine.Debug.LogFormat("{0} {1}", System.DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss.fff"), msg);
}
[Conditional("DEV_VER")]
public static void LogWarning(string msg)
{
UnityEngine.Debug.LogWarningFormat("{0} {1}", System.DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss.fff"), msg);
}
public static void LogError(string msg)
{
UnityEngine.Debug.LogErrorFormat("{0} {1}", System.DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss.fff"), msg);
}
}= [Contidional]을 추가해 빌드 파일을 만들 때에는 개발용 로그가 제외되도록 설정했다.
= Log, LogWarning, LogError을 통해 각 상황별 로그를 다르게 사용하도록 구현했다.
= 로그는 무조건 Logger클래스 내부의 함수들을 통해 구현하기 위해 static을 적용했다.
4. Custom Logger 구현 및 수정
3에서 구현한 코드를 수정해보자. 문제는 아래와 같다.
1) 컨텍스트를 사용하지 않음.
찾아보니 Debug.Log의 가장 강한 기능 중 하나는 로그를 더블 클릭시 하이어라키의 해당 오브젝트를 핑해주는 기능이다.
현재 작성한 코드는 msg만 받아 실행한다.
=> 해당 커스텀 로거만 사용할 경우, 어떤 오브젝트에서 에러가 났는지 판단하기 어렵다.
2) LogFormat에서의 문자열 연산 비용 증가
둘 다 값 타입을 이용할 경우의 문자열로 변환 과정을 비교해 보자.
LogFormat의 경우, 박싱 -> 배열 할당 -> 문자열 생성으로 인해 추가 오버헤드가 생긴다.
String Interpolation은 박싱 -> 문자열 생성으로 인해 LogFormat보다 오버헤드가 적다.
=> 그러므로 LogFormat이 아닌 String Interpolation으로 수정했다.
(++ StringBuilder와 ZString은 런타인 할당을 줄이기 위해 사용되지만, 이미 [Conditional]을 사용했으므로 굳이 사용할 필요가 없다. 로그를 서버로 전송해야 해서 DEV_VER 없이 실제로 로그를 남겨야 하는 경우에는 ZString을 사용해야 한다.)
3) LogError은 빌드 파일에서 제외하기 어려움
LogError은 중요한 코드여서 [Conditional]을 붙여서 빌드 파일에서 제외하기 어렵다.
=> 라이브 서비스 중 에러가 발생할 경우, 그때마다 ToString() 함수가 실행되어 CPU 사용량이 증가하게 된다.
수정한 코드는 아래와 같다.
using UnityEngine;
using System.Collections.Generic;
using System.Collections;
using System.Diagnostics;
//출시용 빌드를 위해 로그 제거
public static class Logger
{
[Conditional("DEV_VER")]
public static void Log(object message, Object context = null)
{
if (context != null)
UnityEngine.Debug.Log($"[{System.DateTime.Now:HH:mm:ss.fff}] {message}", context);
else
UnityEngine.Debug.Log($"[{System.DateTime.Now:HH:mm:ss.fff}] {message}");
}
[Conditional("DEV_VER")]
public static void LogWarning(object message, Object context = null)
{
if (context != null)
UnityEngine.Debug.LogWarning($"[{System.DateTime.Now:HH:mm:ss.fff}] {message}", context);
else
UnityEngine.Debug.LogWarning($"[{System.DateTime.Now:HH:mm:ss.fff}] {message}");
}
public static void LogError(object message, Object context = null)
{
string logMsg = $"[{System.DateTime.Now:HH:mm:ss.fff}] {message}";
if (context != null)
UnityEngine.Debug.LogError(logMsg, context);
else
UnityEngine.Debug.LogError(logMsg);
}
}= String Interpolation을 LogFormat 대신 사용해서 0000
= Object context를 추가해 로그를 찍을 때 this를 넘기면, 콘솔 클릭 시 로그에 대한 오브젝트를 확인할 수 있다.
= 매개변수 타입을 object로 변경해 이전에 값 타입을 넣었을 때 박싱될 수 있는 가능성을 없앴다.
= 릴리즈 빌드에서는 LogError의 시간 부분을 빼야 한다.
5. 작업한 코드 적용
해당 커스텀 로거를 적용하면 아래와 같다.
//원하는 로그 메세지와 함께 로그를 찍을 경우
Logger.LogError("Main Camera not found!", this);
//해당 이벤트의 원인을 로그로 출력할 경우
Logger.Log(reason, this);
6. 후기
프로젝트들을 진행하면서 로그 시스템을 정비하고 싶었는데, 드디어 리팩토링을 해내서 뿌듯하다.
현재는 클라이언트단에서만 로그를 작성하는데, 서버단에서도 로그를 제대로 전달할 수 있도록 수정하도록 프로젝트를 잘 발전시켜야겠다.
7. 출처