Microsoft MVP성태의 닷넷 이야기
스크립트: 45. 파이썬 - uvicorn 사용자 정의 Logger 작성 [링크 복사], [링크+제목 복사],
조회: 9424
글쓴 사람
정성태 (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

비밀번호

댓글 작성자
 




1  2  3  4  5  6  7  8  [9]  10  11  12  13  14  15  ...
NoWriterDateCnt.TitleFile(s)
13557정성태2/18/20244687Windows: 258. Task Scheduler의 Author 속성 값을 변경하는 방법
13556정성태2/17/20244891Windows: 257. Windows - Symbolic (hard/soft) Link 및 Junction 차이점
13555정성태2/15/20245248닷넷: 2216. C# - SemaphoreSlim 사용 시 주의점
13554정성태2/15/20244554VS.NET IDE: 189. Visual Studio - 닷넷 소스코드 디컴파일 찾기가 안 될 때
13553정성태2/14/20244560닷넷: 2215. windbg - thin/fat lock 없이 동작하는 Monitor.Wait + Pulse
13552정성태2/13/20244585닷넷: 2214. windbg - Monitor.Enter의 thin lock과 fat lock
13551정성태2/12/20245382닷넷: 2213. ASP.NET/Core 웹 응용 프로그램 - 2차 스레드의 예외로 인한 비정상 종료
13550정성태2/11/20245442Windows: 256. C# - Server socket이 닫히면 Accept 시켰던 자식 소켓이 닫힐까요?
13549정성태2/3/20245762개발 환경 구성: 706. C# - 컨테이너에서 실행하기 위한 (소켓) 콘솔 프로젝트 구성
13548정성태2/1/20245520개발 환경 구성: 705. "Docker Desktop for Windows" - ASP.NET Core 응용 프로그램의 소켓 주소 바인딩(IPv4/IPv6 loopback, Any)
13547정성태1/31/20245178개발 환경 구성: 704. Visual Studio - .NET 8 프로젝트부터 dockerfile에 추가된 "USER app" 설정
13546정성태1/30/20244947Windows: 255. (디버거의 영향 등으로) 대상 프로세스가 멈추면 Socket KeepAlive로 연결이 끊길까요?
13545정성태1/30/20244776닷넷: 2212. ASP.NET Core - 우선순위에 따른 HTTP/HTTPS 호스트:포트 바인딩 방법
13544정성태1/30/20244622오류 유형: 894. Microsoft.Data.SqlClient - Could not load file or assembly 'System.Security.Permissions, ...'
13543정성태1/30/20244815Windows: 254. Windows - 기본 사용 중인 5357 포트 비활성화는 방법
13542정성태1/30/20244491오류 유형: 893. Visual Studio - Web Application을 실행하지 못하는 IISExpress - 두 번째 이야기
13541정성태1/29/20245005VS.NET IDE: 188. launchSettings.json의 useSSL 옵션
13540정성태1/29/20245144Linux: 69. 리눅스 - "Docker Desktop for Windows" Container 환경에서 IPv6 Loopback Address 바인딩 오류
13539정성태1/26/20245234개발 환경 구성: 703. Visual Studio - launchSettings.json을 이용한 HTTP/HTTPS 포트 바인딩
13538정성태1/25/20245610닷넷: 2211. C# - NonGC(FOH) 영역에 .NET 개체를 생성파일 다운로드1
13537정성태1/24/20245733닷넷: 2210. C# - Native 메모리에 .NET 개체를 생성파일 다운로드1
13536정성태1/23/20245589닷넷: 2209. .NET 8 - NonGC Heap / FOH (Frozen Object Heap) [1]
13535정성태1/22/20245649닷넷: 2208. C# - GCHandle 구조체의 메모리 분석
13534정성태1/21/20245361닷넷: 2207. C# - SQL Server DB를 bacpac으로 Export/Import파일 다운로드1
13533정성태1/18/20245503닷넷: 2206. C# - TCP KeepAlive의 서버 측 구현파일 다운로드1
13532정성태1/17/20245510닷넷: 2205. C# - SuperSimpleTcp 사용 시 주의할 점파일 다운로드1
1  2  3  4  5  6  7  8  [9]  10  11  12  13  14  15  ...