Microsoft MVP성태의 닷넷 이야기
스크립트: 45. 파이썬 - uvicorn 사용자 정의 Logger 작성 [링크 복사], [링크+제목 복사],
조회: 7485
글쓴 사람
정성태 (techsharer at outlook.com)
홈페이지
첨부 파일
 
(연관된 글이 1개 있습니다.)

파이썬 - uvicorn 사용자 정의 Logger 작성

uvicorn으로,

파이썬 - FastAPI / uvicorn 호스팅 환경에서 asyncio 사용하는 방법
; https://www.sysnet.pe.kr/2/0/13087

파이썬 FastAPI 앱을 호스팅하면,

from fastapi import FastAPI
import nest_asyncio
import os

nest_asyncio.apply()

app = FastAPI()

@app.get("/")
def read_root():
    return "Hello world"

보통 이런 식의 출력을 볼 수 있습니다.

$ uvicorn main:app --reload --host 0.0.0.0 --port 18003 --loop asyncio
INFO:     Will watch for changes in these directories: ['/mnt/d/testprj/test_fastapi']
INFO:     Uvicorn running on http://0.0.0.0:18003 (Press CTRL+C to quit)
INFO:     Started reloader process [7601] using watchgod
INFO:     Started server process [7603]
INFO:     Waiting for application startup.
INFO:     Application startup complete.

그리고 만약 루트(/) 경로를 웹 브라우저에서 방문하면 이런 식의 출력이 추가됩니다.

INFO:     127.0.0.1:45578 - "GET / HTTP/1.1" 200 OK

uvicorn의 출력 로그는 크게 2가지로 나뉘는데요, 하나는 "uvicorn.error" 범주가 있고 또 하나는 "uvicorn.access"가 있습니다. 위의 출력에서 처음 uvicorn을 호스팅할 때 출력한 "INFO"는 (이름과 어울리지 않게) "uvicorn.error"에 속하고, 이후 개별 경로를 방문할 때 발생하는 로그들이 "uvicorn.access"에 속합니다.




예제 코드를 통해 보는 것이 ^^ 더 이해가 빠르겠죠? 예를 들기 위해, 로그를 UDP로 전송하는 경우를 가정해 보겠습니다. 우선, 다음과 같이 logging.Handler를 상속받는 클래스를 하나 만들면 됩니다.

class UdpLogger(logging.Handler):
    def __init__(self, udp_server, udp_port):
        self.endpoint = (udp_server, udp_port)
        self.sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM)

        super().__init__()

    def emit(self, record):
        self.sock.sendto(record.getMessage().encode(), self.endpoint)

위에서 중요한 것은 "emit" 함수인데요, 이것은 logger.Handler에 정의된 함수로, Logger.log/debug/info/warning/error/critical의 모든 호출마다 실행되는 함수입니다.

전달된 record 인자는 LogRecord Objects 타입이어서, 그 타입이 제공하는 필드를 통해 Logger.log/debug/info/warning/error/critical에서 전달한 정보를 구할 수 있습니다. 위의 코드에서는 단순히 record.getMessage()를 UDP 서버로 전송하는 것이기 때문에 사용자가 Logger.info("test")라고 하는 경우 "test"에 해당하는 문자열이 record.getMessage()로 반환됩니다.

이후, 사용은 다음과 같이 할 수 있습니다.

handler = UdpLogger('192.168.100.50', 60900)

logger = logging.getLogger("uvicorn.error")
logger.handlers = []
logger.setLevel(logging.DEBUG)
logger.addHandler(handler)

print('logger installed')

nest_asyncio.apply()

app = FastAPI()

위의 경우 setLevel을 DEBUG로 설정했는데요, Logger가 제공하는 로깅 함수의 수준이 DEBUG/INFO/WARNING/ERROR/CRITICAL 순이기 때문에 모든 로그를 handler에 전달하겠다는 것을 의미합니다.

그래서 다시 실행해 보면,

// 실제 실행된 프로세스의 Log

$ uvicorn main:app --reload --host 0.0.0.0 --port 18003 --loop asyncio
INFO:     Will watch for changes in these directories: ['/mnt/d/workshop2/python-agent/testprj/latest_fastapi']
INFO:     Uvicorn running on http://0.0.0.0:18003 (Press CTRL+C to quit)
INFO:     Started reloader process [7667] using watchgod
logger installed
INFO:     Started server process [7669]
INFO:     Waiting for application startup.
INFO:     Application startup complete.
INFO:     127.0.0.1:56486 - "GET / HTTP/1.1" 200 OK

이번엔 UDP 서버에 다음과 같은 출력을 얻을 수 있습니다.

// UDP 서버에서 받은 LogRecord.getMessage()

Started server process [7683]
Waiting for application startup.
Application startup complete.

보시면 print 코드를 사용한 "logger installed" 메시지가 출력된 후 "GET ..."을 제외한 로그가 들어왔습니다. 이전에 설정했듯이 "GET ..." 로그는 "access log"에 해당하기 때문에 그것도 받고 싶다면 다음과 같이 한 번 더 handler를 추가해야 합니다.

logger2 = logging.getLogger("uvicorn.access")
logger2.handlers = []
logger2.setLevel(logging.DEBUG)
logger2.addHandler(handler)

이렇게 변경하면 이제 UDP 서버 측에서도 다음의 메시지를 받게 됩니다.

127.0.0.1:56748 - "GET / HTTP/1.1" 200

여기서 한 가지 차이점이 있는데요, "uvicorn.error" 범주로 받았던 호스팅 관련 메시지들은 Logger를 추가해도 uvicorn의 콘솔 화면에 여전히 출력되는 반면 "uvicorn.access" 로그의 경우에는 uvicorn 콘솔 화면에 출력되지 않습니다.




Logger를 설정한 경우 가장 중요한 것이 예외 로그일 것입니다. 그런데 이게 좀 애매합니다. ^^; 일부러 다음과 같이 오류가 발생하도록 만들고,

@app.get("/")
def read_root():
    text = None
    text.split(' ')
    return "Hello world"

루트를 방문하면 uvicorn 콘솔 화면에는 이렇게 예외의 모든 정보가 나오지만,

ERROR:    Exception in ASGI application
Traceback (most recent call last):
  File "/home/kevin/.local/lib/python3.8/site-packages/uvicorn/protocols/http/httptools_impl.py", line 372, in run_asgi
    result = await app(self.scope, self.receive, self.send)
  ...[생략]...
  File "/usr/lib/python3.8/asyncio/futures.py", line 178, in result
    raise self._exception
  File "/home/kevin/.local/lib/python3.8/site-packages/anyio/_backends/_asyncio.py", line 867, in run
    result = context.run(func, *args)
  File "/mnt/d/workshop2/python-agent/testprj/latest_fastapi/./main.py", line 48, in read_root
    text.split(' ')
AttributeError: 'NoneType' object has no attribute 'split'

UDP 서버에 출력된 텍스트는, 즉 UdpLogger.emit에 의해 전달된 메시지는 단순히 다음과 같습니다.

Exception in ASGI application

중요한 Traceback 정보가 없군요. ^^; 왜냐하면, 실제로 LogRecord의 getMessage() 함수가 반환하는 값이 그것뿐이기 때문입니다. 이를 위해선 record의 다른 속성을 통해 예외 메시지를 뽑아내서 전송하는 부가 처리를 이렇게 추가해야 합니다.

def emit(self, record):
    import traceback
    self.sock.sendto(record.getMessage().encode(), self.endpoint)
    if record.exc_info is not None:
        ex = record.exc_info[1]
        text = traceback.format_exception(etype=type(ex), value=ex, tb=ex.__traceback__)
        text = ''.join(text)
        self.sock.sendto(text.encode(), self.endpoint)




한 가지 유의해야 할 점이 있다면, logging.Handler로 전달하는 값은 오직 Logger.log/debug/info/warning/error/critical 함수에 의한 호출만을 처리할 수 있다는 점입니다. 즉, uvicorn의 콘솔 화면에 출력되는 모든 메시지가 아니라는 건데요, 일례로 print 함수를 이용한 출력은 콘솔에는 나오지만 logging.Handler로는 잡을 수 없습니다.




[이 글에 대해서 여러분들과 의견을 공유하고 싶습니다. 틀리거나 미흡한 부분 또는 의문 사항이 있으시면 언제든 댓글 남겨주십시오.]

[연관 글]






[최초 등록일: ]
[최종 수정일: 2/17/2023]

Creative Commons License
이 저작물은 크리에이티브 커먼즈 코리아 저작자표시-비영리-변경금지 2.0 대한민국 라이센스에 따라 이용하실 수 있습니다.
by SeongTae Jeong, mailto:techsharer at outlook.com

비밀번호

댓글 작성자
 




... [16]  17  18  19  20  21  22  23  24  25  26  27  28  29  30  ...
NoWriterDateCnt.TitleFile(s)
13304정성태3/31/20236064VS.NET IDE: 181. Visual Studio - C/C++ 프로젝트에 application manifest 적용하는 방법
13303정성태3/30/20235167Windows: 241. 환경 변수 %PATH%에 DLL을 찾는 규칙
13302정성태3/30/20235765Windows: 240. RDP 환경에서 바뀌는 %TEMP% 디렉터리 경로
13301정성태3/29/20235933Windows: 239. C/C++ - Windows 10 Version 1607부터 지원하는 /DEPENDENTLOADFLAG 옵션파일 다운로드1
13300정성태3/28/20235572Windows: 238. Win32 - Modal UI 창에 올바른 Owner(HWND)를 설정해야 하는 이유
13299정성태3/27/20235329Windows: 237. Win32 - 모든 메시지 루프를 탈출하는 WM_QUIT 메시지
13298정성태3/27/20235339Windows: 236. Win32 - MessageBeep 소리가 안 들린다면?
13297정성태3/26/20235997Windows: 235. Win32 - Code Modal과 UI Modal
13296정성태3/25/20235281Windows: 234. IsDialogMessage와 협업하는 WM_GETDLGCODE Win32 메시지 [1]파일 다운로드1
13295정성태3/24/20235609Windows: 233. Win32 - modeless 대화창을 modal처럼 동작하게 만드는 방법파일 다운로드1
13294정성태3/22/20235683.NET Framework: 2105. LargeAddressAware 옵션이 적용된 닷넷 32비트 프로세스의 가용 메모리 - 두 번째
13293정성태3/22/20235615오류 유형: 853. dumpbin - warning LNK4048: Invalid format file; ignored
13292정성태3/21/20235980Windows: 232. C/C++ - 일반 창에도 사용 가능한 IsDialogMessage파일 다운로드1
13291정성태3/20/20236275.NET Framework: 2104. C# Windows Forms - WndProc 재정의와 IMessageFilter 사용 시의 차이점
13290정성태3/19/20235728.NET Framework: 2103. C# - 윈도우에서 기본 제공하는 FindText 대화창 사용법파일 다운로드1
13289정성태3/18/20234877Windows: 231. Win32 - 대화창 템플릿의 2진 리소스를 읽어들여 자식 윈도우를 생성하는 방법파일 다운로드1
13288정성태3/17/20235036Windows: 230. Win32 - 대화창의 DLU 단위를 pixel로 변경하는 방법파일 다운로드1
13287정성태3/16/20235200Windows: 229. Win32 - 대화창 템플릿의 2진 리소스를 읽어들여 윈도우를 직접 띄우는 방법파일 다운로드1
13286정성태3/15/20235624Windows: 228. Win32 - 리소스에 포함된 대화창 Template의 2진 코드 해석 방법
13285정성태3/14/20235204Windows: 227. Win32 C/C++ - Dialog Procedure를 재정의하는 방법파일 다운로드1
13284정성태3/13/20235438Windows: 226. Win32 C/C++ - Dialog에서 값을 반환하는 방법파일 다운로드1
13283정성태3/12/20234789오류 유형: 852. 파이썬 - TypeError: coercing to Unicode: need string or buffer, NoneType found
13282정성태3/12/20235123Linux: 58. WSL - nohup 옵션이 필요한 경우
13281정성태3/12/20235196Windows: 225. 윈도우 바탕화면의 아이콘들이 넓게 퍼지는 경우 [2]
13280정성태3/9/20236068개발 환경 구성: 670. WSL 2에서 호스팅 중인 TCP 서버를 외부에서 접근하는 방법
13279정성태3/9/20235495오류 유형: 851. 파이썬 ModuleNotFoundError: No module named '_cffi_backend'
... [16]  17  18  19  20  21  22  23  24  25  26  27  28  29  30  ...