[파이썬/장고#39] 장고(django)에 로깅(logging) 적용하기 - 로그를 파일로 저장하기

 

 

---

서버에 오류 발생시키기

 

서버 환경에서 프로그램 오류 또는 예기치 못한 오류가 발생할 수도 있다. base_views.py 파일의 index 함수 첫 번째 줄에 다음과 같이 강제로 오류가 발생하도록 코딩해 보자.

 

# D:\projects\mysite\pybo\views\base_views.py

 

이제 index 함수가 호출되면 3을 0으로 나누기 때문에 ZeroDivisionError 오류가 발생하게 된다. 이렇게 수정하고 로컬 서버를 띄워 파이보 메인 페이지에 접속하면 다음과 같은 오류가 발생한다.

 

(mysite) D:\projects\mysite>python manage.py runserver  # 개발 서버 기동

 

ZeroDivisionError 발생

 

 

로컬 서버를 실행했던 명령 프롬프트에서도 다음과 같이 ZeroDivisionError 발생한다.

 

 

하지만 오류를 발생시키는 base_views.py 파일을 운영 서버에 적용하고 파이보 메인 페이지에 접속해 보면 다음과 같은 화면만 볼 수 있다. 

 

그런데 화면에서는 "Server Error (500)"만 표시되므로 어떤 오류가 발생했는지 알 방법이 없다. 그렇다고 화면에서 오류를 표시하기 위해 장고 설정 파일을 DEBUG=True로 변경할 수도 없는 노릇이다. 

 

이런 상황을 해결하기 위해서 가장 좋은 방법은 로그 파일을 이용하는 것이다. 보통 운영 환경은 여러 사람이 사용하기 때문에 화면으로 오류를 식별하는 방법은 좋지 않다. 그래서 보통 운영 환경에서는 오류 식별을 위해 로그 파일을 사용한다.

 

 

---

장고의 DEFAULT_LOGGING 설정 확인하기

 

로그를 파일로 저장하기 위해서는 장고의 DEFAULT_LOGGING 설정을 먼저 알아야 한다. 장고의 DEFAULT_LOGGING 설정은 다음과 같다. 

 

# 장고 DEFAULT_LOGGING 설정 DEFAULT_LOGGING = {     'version': 1,     'disable_existing_loggers': False,     'filters': {         'require_debug_false': {             '()': 'django.utils.log.RequireDebugFalse',         },         'require_debug_true': {             '()': 'django.utils.log.RequireDebugTrue',         },     },     'formatters': {         'django.server': {             '()': 'django.utils.log.ServerFormatter',             'format': '[{server_time}] {message}',             'style': '{',         },     },     'handlers': {         'console': {             'level': 'INFO',             'filters': ['require_debug_true'],             'class': 'logging.StreamHandler',         },         'django.server': {             'level': 'INFO',             'class': 'logging.StreamHandler',             'formatter': 'django.server',         },         'mail_admins': {             'level': 'ERROR',             'filters': ['require_debug_false'],             'class': 'django.utils.log.AdminEmailHandler'         },     },     'loggers': {         'django': {             'handlers': ['console', 'mail_admins'],             'level': 'INFO',         },         'django.server': {             'handlers': ['django.server'],             'level': 'INFO',             'propagate': False,         },     } }

 

이 설정에 사용된 항목을 하나씩 살펴보자.

 

version

version은 고정값 1을 사용해야 한다. 만약 다른 값을 입력하면 ValueErorr가 발생한다. 이 값은 의미가 없어 보일 수도 있지만, logging 모듈이 업그레이드되어도 현재 설정을 보장해 주는 안전장치이다.

 

 

disable_existing_loggers

disable_existing_loggers 항목은 False로 설정했다. 만약 True로 설정하면 기존에 설정된 로거들을 사용하지 않게 된다. 파이보도 기존에 설정된 로거를 비활성화할 특별한 이유가 없으므로 False로 설정할 것이다. 

 

 

filter

필터는 특정 조건에서 로그를 출력하거나 출력하지 않기 위해서 사용된다. 'require_debug_false' 필터는 DEBUG=False 인지를 판단하는 필터이고, 'require_debug_true'는 DEBUG=True 인지를 판단하는 필터이다. 조건 판단을 위해 각각 'django.utils.log.RequireDebugFalse' 와 'django.utils.log.RequireDebugTrue' 클래스를 호출하여 DEBUG 항목의 True, False를 판단한다. 

 

 

formatters

포맷터에는 로그를 출력할 형식을 정의한다. 포맷터에 사용된 항목은 다음과 같다.

• server_time - 서버의 시간
• message - 출력 내용

 

 

handlers

핸들러는 로그의 출력 방법을 정의한다. 다음은 DEFAULT_LOGGING 설정에 등록된 핸들러이다.

 

• console - 콘솔에 로그를 출력한다. 로그 레벨이 INFO 이상이고 DEBUG=True 일 때만 로그를 출력한다.
• django.server - python manage.py runserver로 작동하는 개발 서버에서만 사용하는 핸들러로 콘솔에 로그를 출력한다.
• mail_admins - 로그 내용을 이메일로 전송하는 핸들러로, 로그 레벨이 ERROR 이상이고, DEBUG=False일 때만 로그를 전송한다. 핸들러 사용 조건은 환경설정 파일에 ADMINS라는 항목을 추가하고 관리자 이메일을 등록해야 한다. (ADMINS = ['xxx@gmail.com']) 이메일 발송을 위한 SMTP 설정도 필요하다.

 

loggers

로그를 출력하는 프로그램에서 사용하는 로거의 이름을 의미한다. DEFAULT_LOGGING 설정에는 다음과 같은 로거들이 등록되어 있다. 

 

• django - 장고 프레임워크가 사용하는 로거로 로그 레벨이 INFO 이상일 경우에만 로그를 출력한다. 
• django.server - 개발 서버가 사용하는 로거로 로그 레벨이 INFO 이상일 경우에만 로그를 출력한다.
• 'propagate': False의 의미는 django.server가 출력하는 로그를 django 로거로 전달하지 않는다는 의미이다. 만약 'propagate': True로 설정하면 최상위 패키지명이 django로 동일하기 때문에 django.server 하위 패키지에서 출력하는 로그가 django.server로거에도 출력되고 django 로거에도 출력되어 이중으로 출력될 것이다. 

 

★ 로그 레벨 자세히 알아보기

DEBUG < INFO < WARNING < ERROR < CRITICAL

• DEBUG - 디버깅 목적으로 사용
• INFO - 일반 정보를 출력할 목적으로 사용
• WARNING - 경고 정보를 출력할 목적으로 사용
• ERROR - 오류 정보를 출력할 목적으로 사용
• CRITICAL - 아주 심각한 문제를 출력할 목적으로 사용

만약 핸들러나 로거에서 로그 레벨을 INFO로 설정하면 DEBUG로 출력한 로그는 출력되지 않고 INFO 이상으로 출력한 로그들만 출력된다. 만약 ERROR로 설정했다면 ERROR 또는 CRITICAL로 출력한 로그들만 출력될 것이다.

---

☞ 장로 로깅에 대한 보다 자세한 내용은 아래의 URL을 참고하도록 하자.

https://docs.djangoproject.com/en/3.0/topics/logging/

Logging | Django documentation | Django

 

---

 

 

 

 

 

 

---

파이보 로깅 설정하기

 

현재는 서버 환경에서 발생한 오류를 확인할 방법이 없으므로 아래와 같은 방법을 사용해야 한다.

 

◆ 서버 환경에서 발생한 오류를 확인하는 방법

1. 오류 발생 시 관리자 이메일로 오류 내용을 발송
2. 서버 환경에서 오류 발생 시 특정 파일에 로그 출력

 

 

(1단계) LOGGING 설정 복사하기 

 

DEFAULT_LOGGING을 settings/base.py에 LOGGING이라는 변수명으로 바꾸고 내용은 그대로 복사해 준다. 환경 파일에 LOGGING이라는 항목을 설정하면 장고는 로깅 설정으로 인식한다. 

 

# D:\projects\mysite\config\settings\base.py (... 생략...)  # 로깅 설정 LOGGING = {     'version': 1,   (... 생략... 위의 DEFAULT_LOGGING과 내용 동일) }

 

 

(2단계) 포맷터 추가하기

 

앞으로 생성할 로그 파일에 사용할 포맷터 standard를 다음과 같이 추가한다. 

 

# D:\projects\mysite\config\settings\base.py (... 생략...)      'formatters': {         'django.server': {             '()': 'django.utils.log.ServerFormatter',             'format': '[{server_time}] {message}',             'style': '{',         },         'standard': {             'format': '%(asctime)s [%(levelname)s] %(name)s: %(message)s'         },     }, (... 생략...)

 

standard 포맷터에 사용된 항목은 다음과 같다.

• asctime - 현재 시간
• levelname - 로그의 레벨(DEBUG, INFO, WARNING, ERROR, CRITICAL)
• name - 로거명
• message - 출력 내용

 

 

(3단계) 핸들러 추가하기

 

handlers에 file 핸들러를 다음과 같이 추가해 준다.

 

# D:\projects\mysite\config\settings\base.py (... 생략...)      'handlers': {         (... 생략...)          'file': {             'level': 'INFO',             'filters': ['require_debug_false'],             'class': 'logging.handlers.RotatingFileHandler',             'filename': BASE_DIR / 'logs/mysite.log',             'maxBytes': 1024*1024*5,  # 5MB             'backupCount': 5,             'formatter': 'standard',         },     }, (... 생략...)

 

file 핸들러에 사용된 항목은 다음과 같다.

• level - 출력 레벨로 INFO 사용
• filters - DEBUG=False 인 운영 환경에서 사용
• class - 파일 핸들러로 RotatingFileHandler 사용, RotatingFileHandler는 파일 크기가 설정한 크기보다 커지면 파일 뒤에 인덱스를 붙여서 백업한다. 이 핸들러의 장점은 로그가 무한히 증가되더라도 일정 개수의 파일로 롤링(Rolling)되기 때문에 로그 파일이 너무 커져서 디스크가 꽉 차는 위험을 방지할 수 있다.
• filename - 로그 파일명은 logs 디렉터리에 mysite.log로 설정
• maxBytes - 로그 파일 크기는 5MB로 설정
• backupCount - 롤링되는 파일의 개수를 의미한다. 총 5개의 로그 파일로 유지되도록 설정했다.
• formatter - 포맷터는 standard를 사용

 

 

(4단계) 핸들러 등록하기 

 

그리고 django 로거의 handlers에 file 핸들러를 다음과 같이 추가한다.

 

# D:\projects\mysite\config\settings\base.py (... 생략...)      'loggers': {         'django': {             'handlers': ['console', 'mail_admins', 'file'],             'level': 'INFO',         },         'django.server': {             'handlers': ['django.server'],             'level': 'INFO',             'propagate': False,         },     } (... 생략...)

 

이렇게 변경하고 git 을 이용하여 base.py 파일의 변경 내역을 서버에 적용하자.

 

로컬 cmd - 커밋 후 git push

 

MobaXterm - git pull

 

 

(5단계) logs 디렉터리 생성하기

 

서버에 logs 디렉터리를 반드시 생성해야 한다. 

 

# MobaXterm (mysite) ubuntu@ip-172-26-8-122:~/projects/mysite$ mkdir logs (mysite) ubuntu@ip-172-26-8-122:~/projects/mysite$

 

만약 logs 디렉터리를 생성하지 않고 GuniCorn을 재시작하면 502 오류가 발생한다.

 

★ GuniCorn 재시작 

 

마찬가지로 개발 환경에서도 logs 디렉터리를 생성해 주어야 한다.

 

 

(6단계) logs 디렉터리 .gitignore 파일에 추가하기

 

logs 디렉터리는 버전 관리 대상이 아니므로 .gitignore 파일에도 logs 디렉터리를 추가한다.

 

# D:\projects\mysite\.gitignore .idea db.sqlite3 *.pyc __pychche__ logs

 

 

(7단계) 로그 확인하기

 

이제 다시 서버에서 파이보 메인 페이지에 접속해 보자. base_views.py 파일의 index 함수에서 3을 0으로 나누기 때문에 여전히 Server Error(500) 오류가 발생할 것이다. 하지만 이제 오류를 확인할 수 있는 로그 파일을 생성했으므로 해당 오류가 정상적으로 생성되었는지 확인해 보자.

 

ubuntu@ip-172-26-8-122:~$ mysite (mysite) ubuntu@ip-172-26-8-122:~/projects/mysite$ cd logs (mysite) ubuntu@ip-172-26-8-122:~/projects/mysite/logs$ cat mysite.log 2022-11-02 10:27:35,369 [ERROR] django.request: Internal Server Error: / Traceback (most recent call last):   File "/home/ubuntu/venvs/mysite/lib/python3.8/site-packages/django/core/handlers/exception.py", line 47, in inner     response = get_response(request)   File "/home/ubuntu/venvs/mysite/lib/python3.8/site-packages/django/core/handlers/base.py", line 179, in _get_response     response = wrapped_callback(request, *callback_args, **callback_kwargs)   File "/home/ubuntu/projects/mysite/pybo/views/base_views.py", line 14, in index     3/0 ZeroDivisionError: division by zero 2022-11-02 10:28:24,342 [ERROR] django.security.DisallowedHost: Invalid HTTP_HOST header: '/tmp/gunicorn.sock:'. The domain name provided is not valid according to RFC 1034/1035. 2022-11-02 10:28:24,351 [WARNING] django.request: Bad Request: /cgi-bin/kerbynet (mysite) ubuntu@ip-172-26-8-122:~/projects/mysite/logs$

 

※ cat 명령어

:파일 내용 전체를 출력하는 유닉스 명령어

보통 로그를 확인할 때는 cat 보다는 tail -f mysite.log를 주로 사용한다. 

tail -f mysite.log를 실행하면 mysite.log 파일에 로그가 쌓일 때마다 로그의 내용이 자동으로 출력된다.

 

 

---

파이보에서 직접 로그 출력하도록 설정하기

 

앞에서 설정한 LOGGING은 장고가 사용하는 django와 django.server라는 로거만 사용했다. 이번에는 새로운 로거를 생성하여 파이보 프로그램에서 로그를 직접 출력하는 방법을 알아보자.

 

 

(1단계) pybo 로거 생성하기 

 

base_views.py 파일의 index 함수에 임시로 작성한 3/0 코드는 삭제하고 다음과 같이 수정한다.

 

# D:\projects\mysite\pybo\views\base_views.py (... 생략....) import logging logger = logging.getLogger('pybo') # Create your views here. def index(request):     logger.info("INFO 레벨로 출력")     (... 생략...)

 

로그 파일에 로그를 출력하기 위해서는 logging 모듈이 필요하다. logger = logging.getLogger("로거명")으로 얻은 logger 객체를 이용하여 logger.debug, logger.error, logger.warning 등의 함수를 이용하여 로그를 출력할 수 있다. 하지만 이렇게 수정하더라도 "INFO 레벨로 출력"이라는 문장은 로그에 출력되지 않는다. 왜냐하면 위 코드에서 사용한 pybo라는 로거는 LOGGING 설정에 등록되지 않았기 때문이다.

 

 

(2단계) pybo 로거 등록하기

 

따라서 LOGGING 설정에 pybo라는 로거를 등록해야 한다. 다음처럼 pybo 로거를 settings/base.py 파일에 추가한다.

 

# D:\projects\mysite\config\settings\base.py     'loggers': {         'django': {             'handlers': ['console', 'mail_admins', 'file'],             'level': 'INFO',         },         'django.server': {             'handlers': ['django.server'],             'level': 'INFO',             'propagate': False,         },         'pybo': {             'handlers': ['console', 'file'],             'level': 'INFO',         },     }

 

console과 file 핸들러를 사용하는 pybo 로거를 등록했다.

 

 

(3단계) 출력 로그 확인하기

 

이제 서버에 변경 내역을 적용하고 파이보 메인 페이지에 접속하면 다음처럼 mysite.log 파일에 우리가 작성한 로그가 출력된다. 

 

로컬 cmd - git push

 

MobaXterm - git pull

 

GuniCorn을 재시작하고 페이지에 접속한 후 로그를 확인해 본다.

 

(mysite) ubuntu@ip-172-26-8-122:~/projects/mysite/logs$ tail -f mysite.log

 

※ __name__으로 로거 생성하기

logger = logging.getLogger('pybo') 대신 logger = getLogger(__name__)처럼 코딩해도 로그가 잘 출력된다. __name__은 실행되는 파이썬 모듈명을 의미하므로 __name__은 pybo.views.base_views 으로 해석돼서 결국 pybo.views.base_views는 pybo로 시작하는 패키지이므로 동일한 pybo 로거를 사용하게 된다.

 

 

 

---

 

여기까지.