Copilot의 메모리 누수 문제

 (stevenharman.net)
1P by GN⁺ | ★ favorite | 댓글 1개
  • 10년 된 Rails 프로덕션 앱의 web Dyno 메모리가 배포 중 급증했고, 400~500 req/s의 지속 부하와 피크 시 수천 req/s를 처리하는 서비스라 빠른 완화가 필요했음
  • Heroku에서 메모리 한계에 가까운 Dyno를 재시작하고 최근 3일간의 코드·메트릭 변경을 되돌렸지만 메모리 누수는 계속됨
  • Sidekiq와 Delayed::Job은 정상인 반면, Puma worker 일부만 커지는 패턴이 보여 특정 트래픽 종류와의 연관성이 의심됨
  • rbtrace, ObjectSpace, heapy, sheap, reap으로 힙을 추적한 결과, Puma 요청 처리 스레드가 ActiveSupport::Notifications::Event의 @children 배열을 통해 32,067개 객체와 1.9GiB 메모리를 붙잡고 있었음
  • 조작된 쿼리 파라미터가 Bugsnag의 URL 정리 과정에서 URI::InvalidURIError를 일으켰고, 단기 대응은 Bugsnag 업그레이드, 장기 대응은 Rails 업그레이드였음

운영 중인 Rails 앱에서 누수가 시작됨

  • 대상은 10년 된 Rails 앱으로, 실제 매출을 만드는 프로덕션 서비스였음
  • 평상시 지속 부하는 400~500 req/s였고, 피크는 초당 수천 요청까지 올라감
  • 일반적인 배포 흐름 중 메모리 스파이크가 시작됐고, 페이저 알림이 발생함
  • Heroku에서 실행 중이어서 Dyno별 메모리 수치를 기준으로 상태를 봄

장애 완화는 Dyno 재시작으로 시작함

  • 현상은 단순 메모리 팽창(bloat)이 아니라 누수처럼 보였고, 임시 해결책은 프로세스 재시작이었음
  • 평소 여러 번의 일일 배포가 web 인스턴스를 재시작했지만, 메모리 한계에 접근한 Dyno는 수동으로 재시작함

의심 변경을 되돌려도 누수는 남아 있음

  • 첫 번째 큰 스파이크 직전부터 거슬러 올라가며 3일치 코드 변경을 감사함
  • 관련 가능성이 있어 보인 변경은 세 가지였음
    • development 모드에서 Rails 코드 리로딩 때문에 메모리 누수를 일으키는 변경
    • 특정 요청 필터링 중 Redis 호출이 의도보다 많아지는 변경
    • 더 많은 데이터베이스 호출과 ActiveRecord 인스턴스 로딩을 유발하는 N+1 형태의 변경
  • 앞의 두 변경은 수정하고, 세 번째 변경은 롤백한 뒤 하나씩 배포했지만 누수는 계속됨
  • Ruby 언어 메트릭과 Puma pool 사용량 메트릭을 수집하기 위한 도구 변경도 되돌렸으나 메모리 증가는 멈추지 않음

누수 패턴은 특정 트래픽을 가리킴

  • 누수는 web Dyno에서만 발생했고, Sidekiq와 Delayed::Job Dyno는 정상적으로 보였음
  • 모든 web Dyno가 항상 누수되는 것은 아니었음
    • 몇 시간 동안 장기 실행 웹 프로세스처럼 비교적 평탄한 메모리 사용량을 보임
    • 이후 어느 순간 하나, 일부, 또는 전체 Dyno가 누수되기 시작함
  • Puma는 클러스터 모드로 실행됐고, Dyno마다 8 vCPU에 대해 12 worker process를 사용함
  • 한 Dyno 안에서도 12개 worker 중 일부만 거의 모든 메모리를 사용하는 경우가 있었음
  • OpenTelemetry Traces는 샘플링이 강해 특정 요청 종류와 특정 Dyno를 연결하기 어려웠고, 샘플링되지 않는 로그와의 상관분석도 도구상 쉽지 않았음

힙 덤프를 수집하는 절차

  • 실행 중인 Ruby 프로세스에 붙기 위해 rbtrace를 사용함
  • rbtrace는 프로세스에 로드돼 있어야 하므로 Gemfile에 포함했고, 환경 변수로 로딩 여부를 제어함
gem "rbtrace", require: String(ENV.fetch("FEATURE_ENABLE_MEMORY_DUMPS", false)) == "true"
  • Heroku에서는 heroku ps:exec로 누수 중인 Dyno에 SSH 터널을 열고, ps로 Ruby 프로세스를 RSS 기준 정렬함
ps -eo pid,ppid,comm,rss,vsz --sort -rss | grep ruby
  • web Dyno에서는 같은 PPID를 가진 프로세스들이 Puma worker이고, 가장 많은 메모리를 쓰는 worker의 PID를 대상으로 삼음
  • 메모리 할당 추적은 ObjectSpace.trace_object_allocations_start로 켰고, 성능·메모리·CPU에 영향을 줄 수 있음
DUMP_PID=<pid>
rbtrace --pid="${DUMP_PID}" --eval="Thread.new{require 'objspace';ObjectSpace.trace_object_allocations_start}.join"
  • 힙 덤프는 ObjectSpace.dump_all로 /tmp에 생성했고, 몇 시간 실행된 누수 프로세스에서는 JSON 파일이 5~6GiB까지 커짐
rbtrace --pid="${DUMP_PID}" --eval="Thread.new{require 'objspace'; GC.start(); io=File.open('/tmp/heap-${DUMP_PID}.json', 'w'); ObjectSpace.dump_all(output: io); io.close}.join" --timeout=600
gzip "/tmp/heap-${DUMP_PID}.json"
  • Heroku에서는 heroku ps:copy로 덤프를 로컬로 가져왔고, heapy로 retained memory를 보려면 최소 세 개 정도의 덤프를 수집함
  • 작업 후에는 할당 추적을 끄고 덤프를 지우거나 Dyno를 재시작함

힙 분석에서 1.9GiB를 붙잡은 Thread가 드러남

  • heapy의 retained memory 보고서와 sheap diff만으로는 시작점을 찾기 어려웠음
  • Ruby 힙 덤프의 참조 그래프를 분석하고 시각화하는 reap으로 플레임 그래프를 생성함
  • 플레임 그래프는 Ruby GC 관점의 root에서 아래쪽 객체로 이어지는 참조를 보여주며, 더 많은 메모리를 붙잡는 객체일수록 셀이 넓게 표시됨
  • 세 번째 힙 덤프에서 한 Thread가 1.9GiB 메모리를 붙잡고 있었음
  • 실제로는 아래쪽의 Array가 32,067개 객체를 참조하며 1.9GiB를 유지하고 있었음

sheap으로 참조 경로를 따라감

  • 최신 main 브랜치의 sheap을 사용해 두 번째와 세 번째 덤프를 비교함
  • 덤프 크기가 6GiB에 가까워 파싱에 시간이 걸림
  • find_path 결과, 문제의 Thread는 텔레메트리나 메트릭 도구의 백그라운드 스레드가 아니라 요청을 처리하는 Puma thread였음
  • ActiveSupport::SubscriberQueueRegistry는 Rails 6.1에서 이벤트 이름별 ActiveSupport::Subscriber 목록을 저장하는 스레드별 Hash로 동작함
  • 해당 registry는 Hash를 참조했고, 그 안의 Array 중 하나가 ActiveSupport::Notifications::Event를 붙잡고 있었음
  • 그 Event는 다시 @children 배열을 통해 32,067개 이상의 child Event 객체를 참조함
  • 첫 child Event의 이름은 redirect_to.action_controller였고, 내부에는 ActionDispatch::Request 객체가 포함돼 있었음

이상 요청이 재현 단서가 됨

  • 힙 안의 ActionDispatch::Request에는 실제 라우트와 유효한 공개 리소스 ID가 있었지만, 쿼리 파라미터는 조작된 형태였음
  • 요청 경로에는 password=[FILTERED]가 포함돼 있었고, 민감 정보 정리 과정이 개입했음을 보여줌
  • 같은 경로와 파라미터로 프로덕션 앱을 시크릿 브라우저에서 요청하자 500 server error가 발생함
  • 로그에는 URI::InvalidURIError가 남았고, 요청이 도달한 Dyno도 확인할 수 있었음
  • 해당 Dyno는 당시 정상 메모리 사용량을 보였지만, 잠시 배포를 멈추고 관찰하자 누수 추세가 나타남
  • 로컬에서는 activesupport Gem에 binding.pry와 puts 디버깅을 넣어 같은 상황과 백트레이스를 재현함

실제 원인은 Rails와 Bugsnag 변경의 조합이었음

  • 에러 백트레이스는 Ruby 표준 라이브러리의 uri Gem을 가리켰고, 이는 Bugsnag의 Bugsnag.cleaner.clean_url에서 사용되고 있었음
  • 이 코드는 ActiveSupport::Notifications.subscribe 블록 안에서 Rails breadcrumb URL을 정리하는 과정에 있었음
  • 문제는 두 가지가 결합된 형태였음
    • Rails 6.1의 ActiveSupport::Subscriber는 Event#children과 shared Array로 이벤트를 추적함
    • Bugsnag 변경은 Rails breadcrumb URL 정리를 위해 URI를 사용했고, 잘못된 URI에서 예외가 발생할 수 있었음
  • URI가 invalid URI에서 에러를 올리면 Bugsnag의 subscribe 블록이 ActiveSupport::Notifications::Event 처리 중 예외를 발생시킴
  • 그 예외 때문에 parent Event가 Subscriber#event_stack에서 pop되지 않았고, parent Event가 남아 메모리를 누수함
  • parent Event는 #children 배열로 child Event를 계속 참조해 더 많은 메모리를 유지함
  • John Hawthorn의 Rails 7.1 수정은 Event#children 개념과 이벤트 추적용 shared Array를 제거해 두 누수 원인을 함께 없앰

해결책은 Bugsnag 업그레이드와 Rails 업그레이드였음

  • Rails 최신 버전에서는 John Hawthorn의 수정 때문에 이 문제가 더 이상 발생하지 않음
  • 당시 앱은 Rails 6.1이어서 즉시 Rails 수정 효과를 받을 수 없었음
  • Bugsnag는 이미 Bugsnag.cleaner.clean_url이 invalid URI에서 예외를 올리지 않도록 수정한 상태였음
  • 단기 해결은 해당 수정이 포함된 Bugsnag Gem 버전으로 업그레이드하는 것이었음
  • 장기 해결은 Rails 버전을 업그레이드하는 것이었음
  • 최초 메모리 스파이크 시점과 맞물린 변경은 Bugsnag v6.26.0에서 v6.26.1로의 업그레이드였고, 목적은 다른 의존성의 deprecation warning을 고치는 것이었음

함께 보면 좋은 글 β

GN⁺   [-]
Hacker News 의견들

  • 수동 메모리 관리가 왜 그렇게 두려운지 이해가 안 됨. RAII와 명확한 소유권 규칙만 있으면 메모리 관리는 쉬운 엔지니어링 작업임
    오히려 참조 카운팅이나 공유 포인터를 강요하는 프레임워크가 더 어렵게 느껴짐. 소유권이 흐려지기 때문임
    직접 만들었으면 직접 해제하고, 넘겼으면 더 이상 신경 쓰지 않음. OS 리소스인 핸들·소켓도 자동 리소스 관리자 없이 수동으로 관리하는데, 굳이 자동 메모리 관리로 설계를 복잡하게 만들 이유가 없어 보임

    • 수동 메모리 관리는 소프트웨어를 추론할 때 인지 부하를 늘림. 작업 기억 용량은 사람마다 크게 다르고, 복잡한 시스템을 설계할 때 성능을 제한하는 요인이 됨
      수년간 개발하면서 대부분의 개발자는 메모리 관리까지 동시에 추론할 만큼 작업 기억 여유가 충분하지 않다고 보게 됐음. 방법을 기계적으로 알아도 머릿속에서 너무 많은 것을 저글링하면 빠뜨리게 됨
      반대로 수동 메모리 관리를 거의 무리 없이 매번 맞히는 소수도 있음. 그들에게는 실제로 쉬운 일이기 때문에 왜 다른 사람들에게 어려운지 잘 와닿지 않음. 이런 사람에게 자동 메모리 관리는 이점은 불분명하고 단점만 커 보일 수 있음
    • 메모리 버그는 이미 해결된 버그 부류에 가깝다고 봄. 순환 참조를 처리할 수 있는 현대적 가비지 컬렉터가 있는 언어를 쓰면 프로젝트 내내 메모리 버그를 하나도 안 만날 가능성이 큼
      대략적으로 말해 이런 버그가 다른 버그로 대체된 게 아니라 그냥 사라진 것임. 프로그래머에게 더 많은 일을 요구하지도 않고, 오히려 수동 메모리 관리보다 할 일을 줄여줌
      물론 가비지 컬렉션이 무조건 이기는 건 아니고 실제 단점도 있음. 하지만 대부분의 프로그램에서는 현대적 가비지 컬렉터가 충분히 좋아서 그 단점이 별 문제가 안 됨
    • 메모리 관리 자체가 어렵다기보다 개발자가 완벽하지 않아서 정의되지 않은 동작과 누수가 전혀 없는 프로그램을 쓰기가 어려움. 한 번의 실수만으로 CVE, 장기 실행 프로그램의 점진적 메모리 증가, 1000번에 한 번 터지는 버그가 생길 수 있음
      논리 버그도 비슷한 문제가 있고 Java 같은 언어에서도 드물게 메모리 누수가 가능하지만, 메모리 안전 언어는 개선임. TypeScript가 JavaScript보다 나은 것과 비슷함. 메모리 오류를 1%에서 0.01%로 줄일 수 있는 자동화가 있는데, 왜 누수와 정의되지 않은 동작 방지를 계속 수동 관심사로 남겨야 하는지 모르겠음
      Java처럼 쉽지만 오버헤드가 있는 가비지 컬렉션 언어를 쓰거나, Rust처럼 학습 곡선은 있지만 오버헤드가 없는 소유권 강제 언어를 쓸 수 있음. 논리 버그도 골치 아프지만 메모리 버그는 명확한 오류 메시지를 주지 않거나 발생해도 프로그램이 멈추지 않는 경우가 있어 특히 악명 높음
      곁가지로, 형식 검증도 버그 한 부류를 사실상 제거하는 방법임. 지금은 정확성이 가장 중요한 시스템에서나 보이는데, 메모리 관리와 달리 단점이 너무 크기 때문임. 코드가 극도로 장황하고 까다로우며 특정 구조를 강제함. 하지만 형식 검증이 더 좋아지면 이것도 더 주류가 될 것이라 봄
    • 10년 동안 24/7 시스템에서 수동 메모리 관리를 했지만 그립지는 않음. 그 자체가 어렵거나 무서운 건 아니지만, 참조 순환이 생길 수 있는 구조나 참조를 이리저리 옮기는 이벤트 핸들러 기반 아키텍처라면 문제 영역에만 집중하는 대신 메모리 관리 설계를 매우 신중히 해야 함
    • 대형 기술 기업 취약점의 35% 가 해제 후 사용 버그 때문이라는 점이 답의 일부임. 심각한 취약점의 90% 이상은 메모리 안전 언어에서는 불가능한 메모리 버그에서 나옴

  • “나는 진짜 프로그래머가 아니다. 되는 것처럼 이것저것 붙여놓고 넘어간다. 진짜 프로그래머들은 ‘동작은 하는데 메모리가 여기저기 새네요. 고쳐야 하지 않을까요’라고 말할 것이다. 나는 그냥 요청 10번마다 Apache를 재시작하겠다.” — Rasmus Lerdorf, PHP Non-Designer
    https://en.wikiquote.org/wiki/Rasmus_Lerdorf

    • 프로세스 수명을 정확히 안다면 free()를 절대 호출하지 않는 것도 유효한 메모리 관리 전략임

  • 예전에 일하던 곳은 메모리 누수로 500만 달러를 날리는 가장 멍청한 방법 상을 받을 만했음
    90년대 Solaris의 프린터 드라이버에 메모리 누수가 있었음[1]. 당시 큰 은행의 계약자로 일했는데, 그 시절에는 계약 확인에서 팩스의 법적 지위가 법정에서 충분히 검증되지 않아 은행들이 거래를 팩스로 기록했음. 팩스를 보내는 시스템은 특정 프린터에도 문서를 보내 거래 확인서를 출력했고, 누군가는 그 확인서를 집어 상대방에게 전화로 읽어줘서 통화 녹음[2]에 남기고 법적으로 확인하는 일을 했음
    어느 날 메모리 누수 때문에 프린터 드라이버가 죽어 확인서 하나가 출력되지 않았고, 담당자가 전화로 읽어주지 못했음. 시장이 크게 움직였고 상대방은 그 거래를 DK 처리했음[3]. 은행 임원들이 아무리 난리를 쳐도 소용없었고, 500만 달러 손실을 장부에 반영한 뒤 그 은행과 다시는 거래하지 않겠다는 정책을 만들었음[4]. 팩스 프린터 작업은 Windows NT로 옮겨짐
    [1] 훌륭한 책 “Expert C Programming”에 따르면 이 문제는 당시 Sun Microsystems CEO였던 Scott McNealy가 CEO임에도 성능이 낮은 워크스테이션을 받아 문제를 자주 겪었고, 충분히 불평한 끝에 개발자들이 결국 고쳤다고 함 https://progforperf.github.io/Expert_C_Programming.pdf
    [2] 은행의 증권 부문 통화는 법무와 컴플라이언스 이유로 거의 항상 녹음됨
    [3] DK는 “Don’t know”의 약자임. 상대가 거래를 “모른다”고 하면 계약이 성립했다는 사실을 다투는 것임
    [4] 상대는 다른 곳에서 거래하고 다른 은행에 수수료를 내면 되니, 아마 우리 쪽이 더 손해였을 것임

    • 너무 냉소적인 걸 수도 있지만, 많은 기업이 자기에게 엄청난 손해가 되는 거래를 사후에 인정할까 싶음. 절차상 문서 확인과 전화 확인이 필요했는데 그 전화가 없었다면, 왜 상대방이 아니라 이쪽이 손실을 먹어야 하는지 의문임
      Citi도 대출금을 너무 빨리 갚았다는 이유로 소송을 겪었음. 금융권에서는 자기에게 유리하면 누구나 서면 계약을 두고 강하게 나올 거라고 봄

  • C에서는 Valgrind 덕분에 누수 찾기가 아주 쉬움
    고치는 건 더 어렵지만, 설계가 맞다면 보통 쉽다. 보통 호출자를 위해 할당하는 함수가 아닌 이상 같은 함수 안에서 할당하고 해제함. 호출자를 위해 할당하는 함수라면 그 호출 자체를 호출자 쪽의 할당으로 간주함

    • 어려운 건 버그를 재현하는 쪽임
      코드베이스 정적 분석을 했을 때 오류 처리 경로가 문제의 가장 흔한 원인이었음
    • C에서 비슷하게 하지만, 이를 추상화 안의 서로 다른 스코프 수준으로 생각함
      블록 스코프, 함수 스코프, 파일 스코프, 전역 스코프가 있듯이 문제 영역이나 해법의 추상화인 모델에도 여러 수준의 스코프가 있음. 다만 이것이 교육되는 걸 본 적은 없음
      어떤 스코프가 $SCOPE::foo()에서 리소스를 획득하고 $SCOPE::cleanup()에서 해제하지 않는 경우는 눈으로 찾기 꽤 쉬움. 코딩에 뛰어들기 전에 문제 영역과 제안된 해법을 모델링하는 능력은 유용함

  • Yahoo에 대해 들은 이야기가 떠오름. 광고 서버에 메모리 누수가 있어서 대략 10000개 요청 뒤 메모리 부족이 났음
    해결책은 8000개 요청 뒤 서버를 재시작하는 것이었음. 이 방식은 1~2년 통했는데, 이후 8000개 요청 뒤에도 메모리 부족이 나기 시작함
    다음 해결책은 6000개 요청 뒤 서버를 재시작하는 것이었음

    • 평균적인 광고 서버에서 8000개 요청은 대략 500밀리초 정도임
      그 방식이 통하려면 재시작이 엄청나게 빨라야 함

  • Rails 개발자였을 때는 이런 문제에 하드웨어를 더 투입하는 것이 생산성을 위한 괜찮은 절충으로 통했음. 이런 종류의 문제를 신경 쓴다면 더 엄격한 도구를 쓰면 된다는 분위기였음
    개인적으로는 완벽주의 성향 때문에 그 접근을 받아들이기 어렵지만, 실제로 동작한다는 점은 부정하기 힘듦

    • 서버를 10분마다 재부팅해 메모리 누수를 지운다고 인정하는 대신, 단계적 아레나 할당 전략이라고 부르면 괜찮아짐

  • 가비지 컬렉션이 있는 언어와 없는 언어를 둘 다 써봤음. 보통 수동 관리는 작성이 더 어렵고, 자동 관리는 문제 해결이 더 어려움
    둘 다 할 수 있는 언어를 쓰고 싶음. 탐색적 코드를 작성할 때는 자동 메모리 관리가 편하고, 어떤 종류의 코드에는 수동 메모리 관리가 유리함
    금지와 강제 사이의 중간 지점을 못 찾는 게 답답함

    • V는 기본적으로 가비지 컬렉터를 쓰지만, @[manualfree] 속성으로 함수나 모듈별로 쉽게 끌 수 있고 v -gc none으로 프로젝트 전체에서도 끌 수 있음
      https://vlang.io
    • 그 언어는 C++ 임. 거의 수동 메모리 관리를 하지 않지만, 원하면 할 수 있음

  • “누수를 프로파일링하는 여러 도구, 힙 덤프 이해, 흔한 누수 원인에 관해 많은 글이 쓰였다”
    으, 누수와 힙 덤프라니. 누군가는 더 건강한 식단이 필요해 보임

답변달기