관리자 콘솔에서 Sidekiq 큐에 대기 중인 작업과 관련하여 몇 가지 조언이 표시되었습니다. 현재 약 200,000개의 작업이 큐에 쌓여 있으며, 이 문제를 어떻게 해결해야 할지 알 수 없습니다. 현재 실행 중인 버전은 3.2.0입니다.
해당 작업들은 모두 ultra_low 큐에 있으며, Jobs::ProcessPost 작업으로 보입니다. 모두 다음과 유사한 형태입니다:
[{"bypass_bump"=>true, "cooking_options"=>nil, "new_post"=>false, "post_id"=>729508, "skip_pull_hotli...
{"bypass_bump"=>true, "cooking_options"=>nil, "new_post"=>false, "post_id"=>729508, "skip_pull_hotlinked_images"=>false, "current_site_id"=>"default"}
이 작업들을 처리하게 하려면 어떻게 해야 하며, 성능에 큰 영향을 주지 않도록 하는 방법(혹은 그것이 불가피한 경우)은 무엇인가요?
이틀 전에는 약 195K였는데, 지금은 211K까지 늘었습니다. 이 문제를 해결하기 위해 무엇을 확인해야 하는지, 어떻게 해결해야 하는지에 대한 조언이 정말 필요합니다.
아래와 같은 형태의 죽은(dead) 작업 5건을 발견했습니다. (IP 주소는 마스킹 처리되었습니다):
Jobs::HandledExceptionWrapper: Wrapped Errno::ENETUNREACH: Failed to open TCP connection to x.x.x.x:443 (Network is unreachable - connect(2) for "x.x.x.x" port 443)
해당 주소는 인프라에는 있지만 포럼에서는 사용하지 않는 서버(소스 코드 저장소 서버)입니다. 설정 어디에도 이 호스트가 참조되는 부분이 보이지 않아, 왜 이 호스트로 연결해야 한다고 생각하는지 모르겠습니다. 하지만 이것이 ultra_low 큐에 쌓이는 작업 수가 증가하는 것과 관련이 있는 것은 아닌지 궁금합니다.
최근 약 23시간 동안 큐에 7,000개의 작업이 추가되었습니다.
이 문제는 몇 가지 구현 변경 사항도 지연시키고 있습니다. 자동 닫기 기능과 솔루션 플러그인 추가 작업이 그중입니다. 시스템 설정에서 이렇게 중요한 부분을 변경할 때 이 문제로 인해 영향을 받을지, 혹은 문제가 복합적으로 발생할지 모르기 때문에 변경 사항을 진행하지 않으려는 것입니다.
추가된 7,000개의 작업 수는 지난 하루 동안 생성된 새 게시글 수와 일치하지 않아, 이 현상의 원인이 무엇인지 전혀 파악이 되지 않습니다.
이 문제를 해결하는 데 도움이 될 다른 정보가 있을까요?
Ed_S
2월 29, 2024, 6:19오후
4
도움이 되긴 어렵지만, 이 스레드에 대한 더 많은 답변과 좋아요가 쌓이면 마땅히 받을 만한 관심을 끌 수 있을 것 같다는 제안을 드릴 수는 있습니다.
수정: 기본 정렬 방식인 '인기순(hotness)'에 대한 스레드에서도 이 문제를 언급했는데, 이 스레드가 매우 효과적으로, 그리고 매우 불필요하게 숨겨져 있다고 생각합니다.
Falco
2월 29, 2024, 8:47오후
6
전체 백트레이스를 공유해 주시겠습니까? 이는 저희 원박스(onebox) 코드에서 발생한 것으로 추정되지만, 확실하게 확인하고 싶습니다.
이 작업은 콘솔에서 수행해야 할 것 같습니다. 접근 권한이 있는 사람에게 부탁해야 하는데, 접근 권한이 있는 사람에게 전달할 수 있도록 어디서 가져와야 하는지 알려줄 수 있을까요?
감사합니다!
Falco
2월 29, 2024, 10:01오후
8
아니요, 아니요, 오류를 선택하면 /logs 페이지의 탭에 백트레이스가 표시됩니다.
아, 조언해 주셔서 감사합니다. 여기에 표시되는 내용입니다 (IP 주소는 마스킹 처리됨):
Message (10 copies reported)
Job exception: Failed to open TCP connection to x.x.x.x:443 (Network is unreachable - connect(2) for "x.x.x.x" port 443)
Backtrace
/usr/lib64/ruby/gems/3.2.0/gems/net-http-0.4.1/lib/net/http.rb:1603:in `initialize'
/usr/lib64/ruby/gems/3.2.0/gems/net-http-0.4.1/lib/net/http.rb:1603:in `open'
/usr/lib64/ruby/gems/3.2.0/gems/net-http-0.4.1/lib/net/http.rb:1603:in `block in connect'
/usr/lib64/ruby/gems/3.2.0/gems/timeout-0.4.1/lib/timeout.rb:186:in `block in timeout'
/usr/lib64/ruby/gems/3.2.0/gems/timeout-0.4.1/lib/timeout.rb:193:in `timeout'
/usr/lib64/ruby/gems/3.2.0/gems/net-http-0.4.1/lib/net/http.rb:1601:in `connect'
/srv/www/vhosts/discourse/lib/final_destination/http.rb:27:in `block in connect'
/srv/www/vhosts/discourse/lib/final_destination/http.rb:17:in `each'
/srv/www/vhosts/discourse/lib/final_destination/http.rb:17:in `each_with_index'
/srv/www/vhosts/discourse/lib/final_destination/http.rb:17:in `connect'
이것이 “backtrace” 탭의 출력과 다르다는 것을 알아차렸습니다. 하지만 그 출력은 백트레이스로 보이지는 않고, 여기 복사본(복사 버튼 사용)은 백트레이스처럼 보입니다. 이 건에 대해 다른 정보가 필요하면 알려주세요.
이 방법으로 대기 중인 220K+ 작업에 대한 더 많은 정보를 얻을 수 있을지 확인해 보겠습니다. /logs 엔드포인트가 있다는 것을 몰랐거든요.
복사 버튼이 포착한 내용은 전부입니다. 백트레이스 탭에서 가져온 전체 출력은 다음과 같습니다:
net-http-0.4.1/lib/net/http.rb:1603:in `initialize'
net-http-0.4.1/lib/net/http.rb:1603:in `open'
net-http-0.4.1/lib/net/http.rb:1603:in `block in connect'
timeout-0.4.1/lib/timeout.rb:186:in `block in timeout'
timeout-0.4.1/lib/timeout.rb:193:in `timeout'
net-http-0.4.1/lib/net/http.rb:1601:in `connect'
/srv/www/vhosts/discourse/lib/final_destination/http.rb:27:in `block in connect'
/srv/www/vhosts/discourse/lib/final_destination/http.rb:17:in `each'
/srv/www/vhosts/discourse/lib/final_destination/http.rb:17:in `each_with_index'
/srv/www/vhosts/discourse/lib/final_destination/http.rb:17:in `connect'
net-http-0.4.1/lib/net/http.rb:1580:in `do_start'
net-http-0.4.1/lib/net/http.rb:1569:in `start'
net-http-0.4.1/lib/net/http.rb:1029:in `start'
/srv/www/vhosts/discourse/lib/final_destination.rb:551:in `safe_session'
/srv/www/vhosts/discourse/lib/final_destination.rb:486:in `safe_get'
/srv/www/vhosts/discourse/lib/final_destination.rb:170:in `get'
/srv/www/vhosts/discourse/lib/retrieve_title.rb:90:in `fetch_title'
/srv/www/vhosts/discourse/lib/retrieve_title.rb:12:in `crawl'
/srv/www/vhosts/discourse/lib/inline_oneboxer.rb:76:in `lookup'
/srv/www/vhosts/discourse/lib/cooked_processor_mixin.rb:310:in `process_inline_onebox'
/srv/www/vhosts/discourse/lib/cooked_processor_mixin.rb:39:in `block in post_process_oneboxes'
/srv/www/vhosts/discourse/lib/oneboxer.rb:214:in `block in apply'
/srv/www/vhosts/discourse/lib/oneboxer.rb:162:in `block in each_onebox_link'
nokogiri-1.16.0/lib/nokogiri/xml/node_set.rb:235:in `block in each'
nokogiri-1.16.0/lib/nokogiri/xml/node_set.rb:234:in `upto'
nokogiri-1.16.0/lib/nokogiri/xml/node_set.rb:234:in `each'
/srv/www/vhosts/discourse/lib/oneboxer.rb:162:in `each_onebox_link'
/srv/www/vhosts/discourse/lib/oneboxer.rb:213:in `apply'
/srv/www/vhosts/discourse/lib/cooked_processor_mixin.rb:9:in `post_process_oneboxes'
/srv/www/vhosts/discourse/lib/cooked_post_processor.rb:42:in `block in post_process'
/srv/www/vhosts/discourse/lib/distributed_mutex.rb:53:in `block in synchronize'
/srv/www/vhosts/discourse/lib/distributed_mutex.rb:49:in `synchronize'
/srv/www/vhosts/discourse/lib/distributed_mutex.rb:49:in `synchronize'
/srv/www/vhosts/discourse/lib/distributed_mutex.rb:34:in `synchronize'
/srv/www/vhosts/discourse/lib/cooked_post_processor.rb:38:in `post_process'
/srv/www/vhosts/discourse/app/jobs/regular/process_post.rb:28:in `block in execute'
/srv/www/vhosts/discourse/lib/distributed_mutex.rb:53:in `block in synchronize'
/srv/www/vhosts/discourse/lib/distributed_mutex.rb:49:in `synchronize'
/srv/www/vhosts/discourse/lib/distributed_mutex.rb:49:in `synchronize'
/srv/www/vhosts/discourse/lib/distributed_mutex.rb:34:in `synchronize'
/srv/www/vhosts/discourse/app/jobs/regular/process_post.rb:8:in `execute'
/srv/www/vhosts/discourse/app/jobs/base.rb:297:in `block (2 levels) in perform'
rails_multisite-5.0.0/lib/rails_multisite/connection_management.rb:82:in `with_connection'
/srv/www/vhosts/discourse/app/jobs/base.rb:284:in `block in perform'
/srv/www/vhosts/discourse/app/jobs/base.rb:280:in `each'
/srv/www/vhosts/discourse/app/jobs/base.rb:280:in `perform'
sidekiq-6.5.12/lib/sidekiq/processor.rb:202:in `execute_job'
sidekiq-6.5.12/lib/sidekiq/processor.rb:170:in `block (2 levels) in process'
sidekiq-6.5.12/lib/sidekiq/middleware/chain.rb:177:in `block in invoke'
/srv/www/vhosts/discourse/lib/sidekiq/pausable.rb:132:in `call'
sidekiq-6.5.12/lib/sidekiq/middleware/chain.rb:179:in `block in invoke'
sidekiq-6.5.12/lib/sidekiq/middleware/chain.rb:182:in `invoke'
sidekiq-6.5.12/lib/sidekiq/processor.rb:169:in `block in process'
sidekiq-6.5.12/lib/sidekiq/processor.rb:136:in `block (6 levels) in dispatch'
sidekiq-6.5.12/lib/sidekiq/job_retry.rb:113:in `local'
sidekiq-6.5.12/lib/sidekiq/processor.rb:135:in `block (5 levels) in dispatch'
sidekiq-6.5.12/lib/sidekiq/rails.rb:14:in `block in call'
activesupport-7.0.8/lib/active_support/execution_wrapper.rb:92:in `wrap'
activesupport-7.0.8/lib/active_support/reloader.rb:72:in `block in wrap'
activesupport-7.0.8/lib/active_support/execution_wrapper.rb:92:in `wrap'
activesupport-7.0.8/lib/active_support/reloader.rb:71:in `wrap'
sidekiq-6.5.12/lib/sidekiq/rails.rb:13:in `call'
sidekiq-6.5.12/lib/sidekiq/processor.rb:131:in `block (4 levels) in dispatch'
sidekiq-6.5.12/lib/sidekiq/processor.rb:263:in `stats'
sidekiq-6.5.12/lib/sidekiq/processor.rb:126:in `block (3 levels) in dispatch'
sidekiq-6.5.12/lib/sidekiq/job_logger.rb:13:in `call'
sidekiq-6.5.12/lib/sidekiq/processor.rb:125:in `block (2 levels) in dispatch'
sidekiq-6.5.12/lib/sidekiq/job_retry.rb:80:in `global'
sidekiq-6.5.12/lib/sidekiq/processor.rb:124:in `block in dispatch'
sidekiq-6.5.12/lib/sidekiq/job_logger.rb:39:in `prepare'
sidekiq-6.5.12/lib/sidekiq/processor.rb:123:in `dispatch'
sidekiq-6.5.12/lib/sidekiq/processor.rb:168:in `process'
sidekiq-6.5.12/lib/sidekiq/processor.rb:78:in `process_one'
sidekiq-6.5.12/lib/sidekiq/processor.rb:68:in `run'
sidekiq-6.5.12/lib/sidekiq/component.rb:8:in `watchdog'
sidekiq-6.5.12/lib/sidekiq/component.rb:17:in `block in safe_thread'
전체 출력을 가져오지 못한 점 죄송합니다. 복사 버튼이 더 많은 내용을 가져오지 않은 것이 이상하다고 생각했지만, 필요한 부분만 가져오는 것이라고 잘못 가정했습니다.
Falco
2월 29, 2024, 10:42오후
12
오, 훨씬 낫네요!
이것은 서버의 IP 주소로 해석되는 URL을 가진 인라인 링크가 하나 이상 있다는 것을 의미합니다. 해당 서버에 연결할 수 없는 경우, 오류를 기록하지만, 인라인 원박스(inline onebox)가 트리거하는 “링크 정리(link prettify)” 작업을 수행하지 않고 마크다운 쿡(markdown cook) 프로세스는 계속 진행되어야 합니다.
또 한 가지, Discourse를 어떻게 설치하셨나요? 이 모습은 공식 설치 가이드를 따르지 않은 설치처럼 보입니다.
사실 저는 설치를 직접 수행하지 않았습니다. 인프라 팀이 CI/CD 파이프라인을 통해 배포했을 것으로 생각되지만, 세부 사항은 알지 못합니다.
실패한 메시지는 문제가 아닌 것 같습니다. ultra_low 큐에 대기 중인 작업의 수량이 훨씬 더 큰 문제인 것으로 보입니다. 로그에서 아무것도 찾지 못한 것은 사실입니다(아직 작업이 실제로 실행되지 않았기 때문에 제 입장에서는 당연해 보입니다).
Firepup650
2월 29, 2024, 10:54오후
14
몇 개를 수동으로 강제 실행하면 어떻게 되나요?
웹 UI에서 해당 작업을 강제 실행할 수 있는 옵션을 찾지 못하겠습니다. 인수를 "모두 표시"하거나 작업을 개별적으로 삭제하는 옵션만 있습니다.
Firepup650
2월 29, 2024, 11:05오후
16
음. 제가 도움을 주고 있는 포럼에는 대기 중인 항목이 없어서, 존재하지 않는 버튼을 추천하려 했던 점 죄송합니다.
대기 페이지에 있다고 생각했던 재시도 페이지의 참조
걱정 마세요 - 네, 이 항목들은 Enqueued 페이지(/sidekiq/queues/ultra_low)에 표시됩니다.
큐 페이지 자체를 살펴보니 ultra_low 큐의 지연 시간이 약 1년 정도네요. 즉, 이 문제는 이미 꽤 오래전부터 발생해 왔던 것 같고, 대시보드에서 이를 알리는 경고 알림을 최근에야 받게 된 거 같습니다.
Jobs::ProcessPost 작업에서 보이는 내용을 조금 더 자세히 살펴보니, post_id 값이 역순으로 줄어드는 것으로 보입니다. 큐의 첫 번째와 마지막 작업에서 post ID를 확인해 보니, 날짜가 2012년 게시글(디스코스로 마이그레이션 이전 - 하지만 ‘updated_at’ 타임스탬프는 2022년으로, 이는 우리의 마이그레이션 날짜일 수 있으며 - 확인해 봐야 합니다)과 일치했습니다. 가장 최근 것은 2023년 1월 것이었습니다.
토픽 썸네일 생성을 위한 작업이 가끔은 보이긴 하지만, 꽤 드뭅니다. 8,800페이지가 넘는 큐를 모두 확인할 수는 없지만, 추가되는 것의 대부분은 Jobs::ProcessPost 관련 작업으로 보이며, 토픽의 모든 개별 답변과 초기 게시글로 거슬러 올라가는 것으로 보입니다(가장 오래된 것은 스레드 중간, 가장 최근의 것은 토픽의 루트 게시글이었습니다).
프로덕션 시스템에서 백업을 가져와서 로컬에 설정된 테스트 환경에 로드했습니다. 큐가 전혀 백업되지 않는 것 같습니다. 실제로 큐를 모니터링하는 동안 Job::ProcessPost가 해당 큐에 전혀 표시되지 않습니다. (제가 단순히 놓치고 있는 건지 확인하기 위해, 시스템을 그대로 두면서 큐 화면을 녹화하는 방식으로 설정해 볼 계획입니다.)
이로 인해 두 가지 질문이 생겼습니다.
ProcessPost 작업이 트리거되는 원인은 무엇인가요?
ultra_low 큐가 처리되지 않는 원인은 무엇일까요?
저는 Discourse에서 사용되는 기술(redis, sidekiq, rails)에 대해 전문가 수준은 아니지만, 샌드박스 환경에서 학습하고 실험하는 데는 매우 익숙합니다. 이를 통해 프로덕션 환경에서 누군가가 확인해야 할 사항을 이해하고자 합니다.
좋은 소식은 이 문제가 아직 사용자에게 문제를 일으키지 않는 것 같습니다. 세 번째 질문은 해당 큐를 단순히 정리(purge)하는 것이 도움이 될지, 아니면 해당 작업의 실행을 허용하지 않으면 시스템에 어떤 형태로든 해가 될지 여부입니다.
ETA: 방금 테스트 환경에서 작업 일괄 처리(batch)가 들어오는 것을 확인했고, 그곳에서는 정상적으로 처리되고 있습니다. 따라서 어떤 이유로든 프로덕션 서버에서 큐가 처리되지 않는 것으로 보입니다.
해결책이 나온 것 같습니다. 우리가 사용하는 설치 환경은 openSUSE를 위해 빌드된 패키지를 기반으로 하고 있습니다(우리가 논의해 온 인스턴스는 openSUSE 포럼용 인스턴스입니다). 따라서 사실상 "소스에서 빌드"하는 설치 방식을 사용하고 있는 셈입니다.
개발 환경과 프로덕션 환경이 있으며, ultra_low 큐가 프로덕션 환경의 sidekiq 설정에서 실수로 제외되어 있었습니다. 이 문제는 수정되었으며, 큐가 비어 가고 있고 지연 시간이 1년에서 4주로 줄어든 것으로 보입니다.
이제 이 문제를 해결된 것으로 간주할 수 있을 것 같습니다. 조언을 주신 분들에게 감사드립니다. 덕분에 문제의 원인을 파악하는 데 큰 도움이 되었습니다.
