지난 1주일 동안 다른 포럼에서 3개의 Sidekiq 인스턴스가 멈춰 있는 문제를 목격했습니다. 특별한 상황이 있었던 것은 아니었으며, Sidekiq이 작업을 처리하지 않으면서 5개 중 5개의 작업이 처리 중이라고 표시되고 있을 뿐이었습니다.
흥미로운 점은 이 모든 사례에 공통적으로 존재했던 것이 바로 BotInput 작업 하나였다는 것입니다. 이 작업은 비교적 흔한 작업이지만, 여전히 눈에 띄게 보입니다.
Sidekiq을 재시작하면 모든 것이 정상적으로 작동합니다. 동일한 매개변수로 작업을 수동으로 큐에 넣어도 다시 멈추지 않습니다. 해당 작업이 호출되었던 특정 게시물에도 특별한 점은 없습니다.
여기서 무슨 일이 일어나고 있는지 추적하는 방법에 대해 아이디어를 가진 분이 있을까요?
우리도 이런 식으로 정지되는 현상이 발생하고 있으며, 호스트 측에서는 원인을 파악하지 못하고 있습니다.
대시보드에서 확인되는 내용의 스크린샷이 있으신가요?
가능하시다면 Sidekiq 프로세스에 TTIN 신호를 보내고 여기서 백트레이스를 제공해 주세요.
죄송합니다. 이 문제가 다시 발생하기까지 시간이 좀 걸렸습니다.
sidekiq-clean.txt (35.8 KB)
로그 요약
[default] Thread TID-1ow77
[default] /var/www/discourse/vendor/bundle/ruby/3.3.0/gems/sidekiq-6.5.12/lib/sidekiq/cli.rb:199:in `backtrace'
--
[default] Thread TID-1o1jr
[default] /var/www/discourse/lib/demon/base.rb:234:in `sleep'
--
[default] Thread TID-1o1j7
[default] /var/www/discourse/vendor/bundle/ruby/3.3.0/gems/redis-4.8.1/lib/redis/connection/ruby.rb:57:in `wait_readable'
--
[default] Thread TID-1o1j3
[default] /var/www/discourse/vendor/bundle/ruby/3.3.0/gems/message_bus-4.3.8/lib/message_bus/timer_thread.rb:130:in `sleep'
--
[default] Thread TID-1o1ij AR Pool Reaper
[default] /var/www/discourse/vendor/bundle/ruby/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/reaper.rb:49:in `sleep'
--
[default] Thread TID-1o1hj
[default] <internal:thread_sync>:18:in `pop'
--
[default] Thread TID-1o1gz AR Pool Reaper
[default] /var/www/discourse/vendor/bundle/ruby/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/reaper.rb:49:in `sleep'
--
[default] Thread TID-1o1gv
[default] /var/www/discourse/vendor/bundle/ruby/3.3.0/gems/mini_scheduler-0.18.0/lib/mini_scheduler/manager.rb:18:in `sleep'
--
[default] Thread TID-1o1gb
[default] /var/www/discourse/vendor/bundle/ruby/3.3.0/gems/mini_scheduler-0.18.0/lib/mini_scheduler/manager.rb:32:in `sleep'
--
[default] Thread TID-1otmb
[default] /var/www/discourse/app/models/top_topic.rb:8:in `refresh_daily!'
--
[default] Thread TID-1otkn
[default] /var/www/discourse/app/models/top_topic.rb:8:in `refresh_daily!'
--
[default] Thread TID-1otjz
[default] /var/www/discourse/app/models/top_topic.rb:8:in `refresh_daily!'
--
[default] Thread TID-1otif
[default] /var/www/discourse/app/models/top_topic.rb:8:in `refresh_daily!'
--
[default] Thread TID-1othr
[default] /var/www/discourse/app/models/top_topic.rb:8:in `refresh_daily!'
--
[default] Thread TID-1o1fb
[default] /var/www/discourse/vendor/bundle/ruby/3.3.0/gems/mini_scheduler-0.18.0/lib/mini_scheduler.rb:80:in `sleep'
--
[default] Thread TID-1o1er
[default] /var/www/discourse/lib/mini_scheduler_long_running_job_logger.rb:87:in `sleep'
--
[default] Thread TID-1o1en heartbeat
[default] /var/www/discourse/vendor/bundle/ruby/3.3.0/gems/sidekiq-6.5.12/lib/sidekiq/launcher.rb:76:in `sleep'
--
[default] Thread TID-1o1e3 scheduler
[default] /var/www/discourse/vendor/bundle/ruby/3.3.0/gems/connection_pool-2.5.0/lib/connection_pool/timed_stack.rb:79:in `sleep'
--
[default] Thread TID-1ot4n processor
[default] /var/www/discourse/app/models/email_log.rb:58:in `unique_email_per_post'
--
[default] Thread TID-1ot67 processor
[default] /var/www/discourse/app/models/email_log.rb:58:in `unique_email_per_post'
--
[default] Thread TID-1ot8j processor
[default] /var/www/discourse/app/models/email_log.rb:58:in `unique_email_per_post'
--
[default] Thread TID-1ot5n processor
[default] /usr/local/lib/ruby/3.3.0/bundled_gems.rb:74:in `require'
--
[default] Thread TID-1ot6b processor
[default] /var/www/discourse/lib/distributed_mutex.rb:5:in `<main>'
--
[default] Thread TID-1o0kn final-destination_resolver_thread
[default] <internal:thread_sync>:18:in `pop'
--
[default] Thread TID-1o0k3 Timeout stdlib thread
[default] <internal:thread_sync>:18:in `pop'
@tgxworld 백트레이스를 확인해 보셨나요?
한 달 전 포럼 업그레이드 이후로 Sidekiq 문제가 계속되고 있습니다. Sidekiq를 재시작할 때 어떤 명령어를 사용하시나요? 단순히 sv restart sidekiq만 사용하시나요?
죄송합니다. 아직 살펴볼 기회가 없었습니다. 이번 주 중에 한번 확인해 보겠습니다.
이 작업들은 비동기(async)로 처리되므로, 사용자가 그렇게 했다는 사실을 알 수도 없습니다.
Jobs::BotInput에서도 이 문제가 발생한다는 점이 흥미롭네요. 저희는 전체 서버 중 아주 소수(몇 % 정도)에서만 이 문제를 확인하고 있으며, 내러티브 봇을 상당히 많이 사용하는 인스턴스들에서 발생하는 것으로 보입니다.
아니요, 큐에 대기 중인 다른 모든 작업도 함께 잃어버리게 됩니다.
가장 쉽고 안전한 방법은 컨테이너 내부에서 sv reload unicorn를 실행하는 것입니다.
저희 포럼에서는 그런 상황이 아닙니다. AI는 직원들에게만 표시되며, 직원들이 이를 사용하고 있지 않음을 확인했습니다.
일단 AI를 비활성화해 두었습니다.
BotInput은 AI 봇이 아니라 Discourse 내러티브 봇(또는 Discobot)의 작업입니다.
아. 저는 사용자명 discobot으로 API를 많이 사용해 왔습니다.
백트레이스를 살펴봤는데, 모두 다음 줄에서 문제가 발생하는 것으로 보입니다:
왜 그 줄이 문제를 일으키는지 정확히는 모르지만, 해당 줄은 필수적이지 않으므로 다음 PR에서 제거했습니다:
@RGJ 혹시 Rails.application.config.eager_load를 어떤 이유로 비활성화해 두셨나요? 
흥미로운 발견이네요. 조사해 주셔서 감사합니다.
이처럼 간헐적으로 발생하는 문제가 언제 사라지는지 판단하기는 어렵습니다. 가장 자주 멈췄던 세 인스턴스(그중 하나는 거의 매일 멈췄습니다)에서 해당 줄을 제거했습니다. 다음 두 경우 중 하나에서 다시 확인하겠습니다:
아니요, 그 부분은 건드리지 않았습니다.
하지만 누군가는 건드렸네요…
Rails.autoloaders.main.do_not_eager_load(config.root.join("lib"))
Blaming discourse/config/application.rb at main · discourse/discourse · GitHub 에서 확인됩니다.
@loic 프로덕션 환경에서도 lib 디렉토리를 즉시 로드(eager load)하지 않는 이유가 무엇이었는지 기억하시나요?
이번 주에도 문제가 발생하고는 있지만, 해당 require 줄을 제거한 세 인스턴스에서는 발생하지 않았습니다. 따라서 이것이 원인이었다고 안전하게 가정할 수 있을 것 같습니다 
. @tgxworld 님, 그 부분을 찾아주셔서 감사합니다. 저는 절대 그걸 찾지 못했을 것입니다.
이 수정 사항을 안정 버전(stable)에도 적용해 주실 수 있을까요?
여기에 설명된 내용(Rails 7.1로 업그레이드했을 때)과 관련이 있습니다: Upgrading Ruby on Rails — Ruby on Rails Guides
정확한 문제는 기억나지 않지만, 실제로는 이전 동작 방식을 유지하여 lib에서 필요한 것들을 직접 require하도록 하고 있습니다.
