v Improving debuggability of complex asyncio applications 김준기 | 복잡한 asyncio 앱을 보다 쉽게 디버깅하기

발표자 소개 • PyCon KR/JP/APAC/US 발표 9년 연속... • 래블업 주식회사 CTO Co founder • 전산학 박사 주제 : 이기종 가속기 기반 고속 패킷 처리 프레임워크 • asyncio 생태계 기여 • 취미 피아니스트

asyncio 앱 디버깅할 때 어려움들

프로덕션에서 디버깅하기 • 어려운 문제들 메모리 누수 / CPU 잡아먹기 중요한 비동기 작업이 예기치 못하게 종료되어버리는 경우 중요한 오류 로그가 사라짐 특히 내가 직접 통제할 수 없는 외부 라이브러리 코드에서 문제가 발생한다면?? • asyncio 기반 코드에서 이러한 문제들을 어떻게 다루어야 하는가?

어려운 문제에 대한 접근 방법들 구조적 동시성으로 예방하기 1 사후 분석하기 asyncio.TaskGroup aio-libs/{aiomonitor, aioconsole} asyncio.all_tasks() 실행 중에 들여다보기 aiomonitor v2 작업 종료 체인 분석 aiomonitor v2 작업 생성 체인 분석 asyncio 대안 접근 방법 asyncio.Supervisor asyncio.as_completed_safe() trio.open_nursery() [1] https://vorpus.org/blog/notes-on-structured-concurrency-or-go-statement-considered-harmful/ aiotools.{TaskContext,TaskScope} aiotools.as_completed_safe() ? ? Traceback & logging N/A

Traceback in asyncio • Python traceback이 알려주는 정보 예외의 타입 및 예외객체 생성 시 전달된 인자 스택의 어느 지점에서 예외가 발생하였는지에 대한 정보 • 이것으로 충분할까? 만약 외부 코드가 cancellation을 씹어먹는다면? Task가 종료되었지만 garbage collection이 지연된다면? File "~/workspace/aiomonitor-ng/examples/simple_aiohttp_srv.py", line 11, in inner2 await asyncio.sleep(100) File "~/.pyenv/versions/3.11.3/lib/python3.11/asyncio/tasks.py", line 639, in sleep return await future ^^^^^^^^^^^^ asyncio.exceptions.CancelledError

Traceback in asyncio • 우리가 더 알아야 하는 정보 누가 이 task를 취소했는지? 예 명시적 에러가 발생한 것도 아닌데 task가 사라져버린 경우 누가 이 task를 만들었는지? 예 갑자기 많은 수의 동일 task가 생성되어 성능 저하를 초래할 때 File "~/workspace/aiomonitor-ng/examples/simple_aiohttp_srv.py", line 11, in inner2 await asyncio.sleep(100) File "~/.pyenv/versions/3.11.3/lib/python3.11/asyncio/tasks.py", line 639, in sleep return await future ^^^^^^^^^^^^ asyncio.exceptions.CancelledError https://www.yes24.com/Product/Goods/6073365

asyncio task들의 세계 ... asyncio 앱은 서로 독립된 스택을 가지고 상호작용하는 task tree들의 집합으로 간주할 수 있다. My Code 3rd Party Code My Code 3rd Party Code My Code My Code task stack Error! Swallows cancellation? raise cancel() await ... My Code 3rd Party Code create_task() await await callback task stack

aiomonitor v2 Improving debuggability of complex asyncio applications

aiomonitor 구조 asyncio 앱 프로세스 별도의 터미널 App thread aiomonitor thread Telnet client telnet ui loop REPL with start_monitor(): asyncio event loop

Quick start import aiomonitor async def main(): loop = asyncio.get_running_loop() run_forever = loop.create_future() with aiomonitor.start_monitor(loop): await run_forever try: asyncio.run(main()) except KeyboardInterrupt: pass $ pip install aiomonitor-ng $ edit test.py $ python test.py & $ telnet localhost 50101

Quick start monitor >>> help Usage: help [OPTIONS] COMMAND [ARGS]... To see the usage of each command, run them with "--help" option. Commands: cancel Cancel an indicated task console Switch to async Python REPL exit (q,quit) Leave the monitor client session help (?,h) Show the list of commands ps (p) Show task table ps-terminated (pst,pt) List recently terminated/cancelled tasks signal Send a Unix signal stacktrace (st,stack) Print a stack trace from the event loop thread where (w) Show stack frames and the task creation chain of a task where-terminated (wt) Show stack frames and the termination/cancellation chain of a task

aiomonitor v2 추가 사항 • Task 생성 creation 체인 추적기 • Task 종료 termination 추적기 • Task 취소 cancellation 체인 추적기 • prompt_toolkit Click 통합을 기반으로 CLI 고도화 명령어 및 인자 자동완성 지원 터미널 유형 인식 및 상호작용 가능한 프롬프트 지원

Task 생성 체인 추적기 • Q: 이 task와 그 부모 task들은 누가 만들었나? • 구현 class TracedTrask(asyncio.Task) asyncio.set_task_factory() 덕분에 구현 가능해짐! Task들에 대한 약한 참조 보관 where 명령 실행 시 약한 참조의 체인을 순회하며 스택 정보 출력 • 가정 부모 task는 그 자식 task들이 살아있다면 항상 살아있음 수명주기 포함 관계 구조적 동시성과 asyncio.TaskGroup은 이러한 특성을 유도함 약한 참조만 보관해도 부모를 항상 추적할 수 있으므로 메모리 누수를 방지에 도움

Task 생성 체인 추적기 Task C Task B Task A await ...() ...() create_task(...) await ...() create_task(...) ...() await ...() await ...() create_task(...) Task D await ...() await ...() weak keys ...() Task A Task B Task C Task D Task A Task B Task B stack A stack B stack C stack D weak values _created_traceback_chain: WeakKeyDictionary[Task, weakref.ReferenceType[Task]) _created_tracebacks: WeakKeyDictionary[Task, list[traceback.FrameSummary])

Task 종료 추적기 • Q. 아주 오래 전이라도 어떤 task가 왜 죽었을까? • 구현 _trace_termination() 함수를 task 완료 콜백으로 등록 get_trace_id(): gc 후에는 원래 task object의 id()가 유효하지 않으므로 별도의 ID 생성 원래 task object의 id()와 task 이름 기본값 : Task-XXX, 별도로 지정하지 않으면 asyncio가 단조증가하는 번호를 자동 할당 을 조합하여 해싱 최대 보관 개수를 제한하여 메모리 누수 방지 @preserve_termination_logs 데코레이터를 특정 coroutine 함수에 붙이면 최대 보관 개수와 상관 없이 영원히 종료 로그 보존 장시간 유지되어야 하는 중요 task의 예상치 못한 종료 버그에 대한 분석을 가능하게 함 ps-terminated, where-terminated 명령으로 종료 로그 조회

Task 취소 체인 추적기 • Q: 이 task를 취소한 task는 누구고, 그 task를 취소한 또다른 task는 누구인가? • 구현 Task.cancel() 메소드를 오버라이드 cancel() 안에서 조회하는 current_task() 취소를 요청한 task cancel() 안에서의 self 취소된 task 이 시점에서 취소를 요청한 task의 스택 정보를 얻을 수 있음 스택 정보를 바로 전처리하지 않고 monitor UI thread로 위임하여 tracker 객체 생성 janus를 사용하여 동기/비동기 코드 사이의 자료 주고받기 구현 최대 보관 개수를 초과하면 tracker 객체 삭제 ps-terminated, where-terminated 명령 공유

_termination_info_queue: janus.Queue[TerminatedTaskInfo] Task 종료·취소 체인 추적기 _cancellation_chain_queue: janus.Queue[CancellationChain] Task B Task X await ...() ...() task_b.cancel(...) await ...() Monitor UI thread App thread await ...() canceller cancellee cancel() extract_stack(task) filter_stack(task) cleanup_trackers() task done callback TracedTask.cancel()

prompt toolkit Click 통합 • aiomonitor v2 동시에 여러 텔넷 세션 지원 aio libs/aiomonitor#140 명령어 및 task 참조 ID에 대한 자동완성 지원 / task 목록 필터링 조건 옵션 추가 • 구현 contextvars를 이용하여 각 텔넷 세션마다 다음 오브젝트를 추적 및 공유 monitor 인스턴스 현재 텔넷 연결에 바인딩된 stdout 출력 객체 asyncio.Event를 활용하여 Click command 객체에 작업 완료 여부 통지 직접 ClickCompleter 인터페이스 구현체 제공

Demo

Live task list (abbrev. of long paths)

Filtering the live task list by coro/task names List of terminated / cancelled tasks

A part of task creation chain trace showing that a 3rd party library (grpcio) creates internal sub-tasks ← my code ← 3rd party code

문제 해결 사례

Case: Backend.AI가 멈췄어요! • 증상 : 아무런 오류 로그가 없는데 앱 시작 후 일정 시간이 지나면 모든 사용자 요청 처리가 중단됨 • 분석 : 항상 실행되어야 하는 process_lifecycle_events() task가 갑자기 사라짐... asyncio.TaskGroup를 잘못 사용하여 처리되지 않은 자식 task의 예외로 인해 부모 task까지 함께 종료되어 버림 TaskGroup은 자식 task 중 1개라도 실패하면 바로 전체를 실패로 간주하고 취소 처리하므로, 장시간 실행되면서 자식 task들을 모니터링하는 용도로는 적합하지 않음 Supervisor API의 필요성을 깨닫게 된 계기 • aiomonitor의 task termination log 기능을 통해 발견 및 예외 처리 개선, TaskGroup 사용 중지

Case: Backend.AI가 CPU를 다 잡아먹어요! • 증상 : 특정 고객사에서만 발생하는 속도 저하 및 멈춤 현상 • 분석 : 특정 사용자가 너무 많은 백만 개 이상 의 파일을 한 디렉토리에 넣는 바람에 주기적으로 용량 통계를 구하는 작업의 실행 시간이 실행 주기를 초과하여 무한히 쌓임 실시간 모니터링 결과 6,000개 이상의 task가 쌓였고, 이들은 모두 동일한 executor pool을 공유하고 있어 일종의 thrashing 발생 • aiomonitor의 실시간 task 목록 조회 기능을 통해 문제 파악 및 회피 로직 작성

Case: 외부 의존성에 숨어있는 폭탄... • 증상 : grpcio를 특정 버전으로 업그레이드한 이후 고객사에서 메모리 누수 발견 • 분석 : grpcio 내부 버그로 인해 명시적인 로그인 정보를 사용하는 secure 채널을 사용하여 etcd에 접근하면 특정 콜백 함수의 클린업이 제대로 이루어지지 않음 grpc/grpc#25449 내가 생성한 것이 아닌 grpcio 라이브러리에서 생성한 task가 지나치게 많이 쌓임 • aiomonitor의 task creation chain tracker를 활용하여 문제 파악 및 grpcio 버그 해결 전까지 버전 고정

마무리

교훈 • Debuggability 관찰용이성 observability 재현가능성 reproducibility 런타임에 들여다보기 사후분석을 위한 로깅 • asyncio는 디버깅을 위해 고유의 특화된 도구들이 필요하다! 한 가지 문제 상황에 여러 task가 관여할 수 있고, 나의 통제 밖에 있는 task도 포함될 수 있음 여러 task와 그 stack들을 가로지르는 통합적 시점 holistic view 이 필요함 멀티스레드 코드 디버깅이 어려운 이유와도 일맥상통 • 디버깅을 위한 도구 개선에 꾸준한 관심과 투자가 필요함 당장 제품의 기능이 개선되는 등의 눈에 보이는 성과가 있는 것은 아니지만, 나쁜 일들이 벌어졌을 때 시간과 노력을 크게 아낄 수 있음

PyCon US 2023 Sprint • aio libs 메인테이너의 특훈 ?! https://github.com/webknjaz • 원래 achimnol/aiomonitor ng로 fork했었는데, 아예 aio libs/aiomonitor 메인테이너로 승격 • 각종 CI/CD 도구 및 기법 전수 pre commit.yml 선 패키징 후 테스트 GitHub Actions Environment 릴리즈 전 사전 허가 및 독립된 secret 접근 권한 with Sviatoslav Syndorenko Zac Hatfield Dodds

앞으로 할 일 • Scope로 구분된 실시간 task 목록 보기 구조화된 asyncio 앱 task group의 계층화된 트리 장기간 실행되는 task group supervisor 들의 시각화 그러한 task group들 하위에 속한 task들을 필터링해서 보기 • Top과 같은 실시간 모니터링 화면 예 가장 최근 혹은 이전에 컨텍스트 전환이 발생한 task 순으로 정렬 • 안정성을 위해 subinterpreter 도입하기 Python 3.12 • 성능 최적화 및 pagination 개선 특히 task 개수가 수 천, 수 만 개를 넘어가는 상황에 대비 • PyCon KR Sprint: 웹 기반 모니터링 화면 추가하기

감사합니다! 2015년 창업하여 Python 및 asyncio 기반의 Backend.AI 플랫폼으로 전 세계 70여곳 이상 엔터프라이즈 고객의 AI 개발과 서비스를 돕고 있습니다. 오픈소스와 hard tech 여정에 함께 하실 분들을 환영합니다! https://backend.ai https://lablup.com https://github.com/lablup/backend.ai