[PyCon KR 2023] Improving debuggability of complex asyncio applications

Transcript

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

   View Slide

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

   View Slide

3. asyncio 앱 디버깅할 때 어려움들
   

   View Slide

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

   View Slide

5. 어려운 문제에 대한 접근 방법들
   구조적 동시성으로
   예방하기 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
   

   View Slide

6. 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
   

   View Slide

7. 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
   

   View Slide

8. 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
   

   View Slide

9. aiomonitor v2
   Improving debuggability of complex asyncio applications
   

   View Slide

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

    View Slide

11. 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
    

    View Slide

12. 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
    

    View Slide

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

    View Slide

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

    View Slide

15. 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])
    

    View Slide

16. 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 명령으로 종료 로그 조회
    

    View Slide

17. 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 명령 공유
    

    View Slide

18. _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()
    

    View Slide

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

    View Slide

20. Demo
    

    View Slide

21. Live task list (abbrev. of long paths)
    

    View Slide

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

    View Slide

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

    View Slide

24. 문제 해결 사례
    

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

28. 마무리
    

    View Slide

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

    View Slide

30. 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
    

    View Slide

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

    View Slide

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

    View Slide