1P by neo 2달전 | favorite | 댓글 1개

ActiveSupport::Notifications 관련 Memory Leak 해결 과정 정리

  • Memory Leak가 발생한 상황

    • 특정 시점부터 web Dyno의 메모리 사용량이 비정상적으로 증가하기 시작함
    • Pager가 울리기 시작하고, memory leak으로 보이는 상황 발생
  • 즉각적 대응

    • Heroku에서 memory leak이 의심되면 Dyno를 재시작하는 것으로 임시 해결 가능
    • 정상적인 deploy 주기에 맞춰 restart하거나 memory limit에 가까운 Dyno를 수동으로 재시작
  • 원인 파악을 위한 의심 코드 검토

    • memory spike 직전에 배포된 코드 변경사항 검토
    • 원인으로 의심되는 몇 가지 코드를 하나씩 배포하며 memory leak 발생 여부 확인
    • 원인으로 보이는 코드가 없어 tooling 변경사항도 배포 취소하며 확인. 하지만 memory leak은 지속됨
  • memory 증가 패턴 분석

    • web Dyno에서만 leak 발생. Sidekiq, Delayed::Job Dyno는 정상
    • 모든 web Dyno가 항상 leak 되는 것은 아님. 몇 시간 정상 사용 후 한두개 또는 모든 Dyno에서 leak 시작
    • 트래픽 양 보다는 특정 트래픽에 의해 발생하는 것으로 의심
    • Dyno 내 모든 Puma worker에서 leak이 발생하는 것은 아니고, 소수의 worker에서 전체 메모리의 대부분을 사용 중
  • Heap dump 수집 및 분석

    • rbtrace를 사용해서 leak이 발생 중인 Ruby process의 heap dump 수집
      • heroku ps:exec으로 leak 중인 dyno에 ssh 접속
      • ps 명령으로 가장 메모리를 많이 사용 중인 Ruby worker process 선택
      • rbtrace로 해당 pid에 attach 후 메모리 할당 추적 시작 (ObjectSpace.trace_object_allocations_start)
      • ObjectSpace.dump_all로 heap dump 수집. 용량이 클 경우 gzip 압축
      • heroku ps:copy로 dump 파일 로컬로 가져옴
    • reap을 사용해서 heap dump를 flamegraph로 시각화
      • 1.9GB의 메모리를 참조하고 있는 Thread와 그 아래 32,067개의 객체를 참조하는 Array 발견
    • sheap을 사용해서 의심가는 객체 탐색
      • 해당 Thread는 Puma의 worker thread로 밝혀짐
      • ActiveSupport::SubscriberQueueRegistry 객체가 Hash를 참조하고 있고, 그 아래 StringArray 객체 존재
      • 문제의 Array에는 32,000개 이상의 ActiveSupport::Notifications::Event 객체가 쌓여 있음
  • 원인 추론

    • ActiveSupport::NotificationsEvent 객체가 #children array에 잘못 쌓이고 있다고 추측
    • ActiveSupport::Notifications.instrument block 내에서 에러가 발생하면, 해당 Event#children에서 제거되지 않고 남아서 메모리 누수 발생할 것으로 추정
  • 로컬 재현

    • production에서 발견된 의심가는 request path와 parameter로 로컬에서 요청 전송
    • 500 Internal Server Error와 함께 URI::InvalidURIError 발생 확인
    • 해당 요청을 보낸 production dyno의 memory 사용량이 급격히 증가하는 것을 확인
  • 구체적 원인 분석

    • Rails 7.1에서 고쳐진 ActiveSupport::NotificationsEvent#children 관련 버그가 있었음
    • 여기에 Bugsnag gem에서 request url을 clean하는 과정에서 URI.parseURI::InvalidURIError를 raise하는 버그가 겹쳐서 메모리 누수 발생
    • ActiveSupport::Notifications.subscribe block 내에서 raise한 에러가 잡히지 않아, 해당 Event#children array에서 제거되지 않고 계속 쌓이는 메모리 누수 발생
  • 해결 방안

    • 단기: Bugsnag gem에서 URI::InvalidURIError 발생 시에도 에러를 raise하지 않도록 버전 upgrade
    • 장기: ActiveSupport::Notifications의 버그가 수정된 Rails 7.x로 upgrade

GN⁺의 의견

  • 문제를 발견하고 체계적으로 원인을 파악해 나가는 과정이 인상 깊음. memory leak이 의심될 때 기본적으로 해볼만한 분석 과정을 잘 정리하고 있음
  • Ruby의 heap dump 수집, 시각화, 분석을 위한 다양한 오픈소스 도구(rbtrace, reap, sheap 등)가 활발하게 개발되고 있는 것으로 보임. 꼭 Ruby가 아니더라도 언어별 유용한 memory 분석 도구들을 숙지하고 문제에 적용할 줄 아는 것이 중요해 보임
  • 사실 memory leak의 원인이 사용하는 특정 라이브러리나 프레임워크의 버그인 경우가 많지만, 해당 버그를 직접 분석하고 수정해서 배포할 수 있는 여건은 아니므로, 우회할 수 있는 방법을 최대한 빨리 적용하는 게 중요함. 버그 리포트와 함께 가능한 차선책을 함께 제공하는 것도 좋은 방법
  • 단순히 memory leak을 해결하는 것에 그치지 않고, 문제의 root cause를 깊이있게 파고 들어간 점도 좋았음. 프레임워크 내부 코드를 꼼꼼히 살펴 근본 원인까지 추적하려는 분석 자세가 개발자에게 필요해 보임
  • 결국 memory leak의 원인은 처음에는 전혀 관련 없어 보이는 사소한 라이브러리 버전업에 있었다는 점. 의존성 관리와 변경사항 추적의 중요성을 보여주는 사례. 사소한 변경이라도 영향도를 신중히 분석하고 배포 후에도 모니터링이 필요함을 시사
Hacker News 의견

수동 메모리 관리에 대한 두려움 없이 엔지니어링 훈련으로 해결 가능함

  • RAII와 명확한 소유권 규칙만 있으면 메모리 관리는 쉬운 엔지니어링 작업임
  • 오히려 참조 카운팅과 공유 포인터를 고집하는 프레임워크가 소유권을 모호하게 만들어 더 어려움
  • 생성하면 해제하고, 이전하면 신경쓰지 않는 것이 엔지니어링 규율의 일부임
  • 메모리 버그는 로직 버그와 다를 바 없으므로 고치는 게 당연함
  • OS 자원(핸들, 소켓 등)도 자동 자원 관리자 없이 수동으로 관리하므로 메모리도 마찬가지로 접근 가능함

메모리 누수로 인한 500만 달러 손실 사례

  • 90년대 Solaris 프린터 드라이버의 메모리 누수 버그로 인해 발생한 일화 소개
  • 당시 은행에서 팩스로 거래를 확인하고 프린터로 출력해 상대방과 통화로 읽어주며 녹음하는 방식으로 법적 확인을 받음
  • 메모리 누수로 프린터 드라이버가 다운되어 출력되지 않은 확인서 때문에 거래 취소를 당해 500만 달러 손실을 봄
  • 결국 Sun CEO의 불평으로 개발자들이 버그를 고치게 됨

메모리 누수 디버깅 도구와 해결 방안

  • Valgrind를 사용하면 C에서 누수를 쉽게 찾을 수 있음
  • 설계가 제대로 되어 있다면 대개 할당과 해제를 동일한 함수에서 하므로 고치기 쉬움
  • Yahoo 광고 서버의 메모리 누수 사례와 임시방편 해결책 소개
  • PHP 설계자의 농담 인용문을 통해 완벽주의보다는 실용주의를 택하는 태도 보여줌
  • Rails에서는 생산성을 위해 하드웨어로 해결하는 것이 일반적이라고 함

글쓰기 스타일에 대한 칭찬

  • 글쓴이의 글쓰기 방식이 이모티콘이나 포맷팅 때문인지 즐겁다는 코멘트