Sidekiq 하트비트 테스트 실패, 재시작 중

제품 지원 자체 호스팅
1

안녕하세요! 관리자 페이지에서 sidekiq가 실행되지 않는다는 이상한 오류를 발견했습니다.
로그를 열었더니 다음과 같은 오류가 수백 개 발견되었습니다:

/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/logster-2.5.1/lib/logster/logger.rb:112:in `report_to_store'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/logster-2.5.1/lib/logster/logger.rb:103:in `add_with_opts'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/logster-2.5.1/lib/logster/logger.rb:54:in `add'
/usr/local/lib/ruby/2.6.0/logger.rb:534:in `warn'
config/unicorn.conf.rb:147:in `check_sidekiq_heartbeat'
config/unicorn.conf.rb:164:in `master_sleep'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/unicorn-5.5.2/lib/unicorn/http_server.rb:296:in `join'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/unicorn-5.5.2/bin/unicorn:128:in `<top (required)>'
/var/www/discourse/vendor/bundle/ruby/2.6.0/bin/unicorn:23:in `load'
/var/www/discourse/vendor/bundle/ruby/2.6.0/bin/unicorn:23:in `<main>'

앱에서 발생한 오류는 다음과 같습니다.

run-parts: executing /etc/runit/1.d/00-ensure-links
run-parts: executing /etc/runit/1.d/00-fix-var-logs
run-parts: executing /etc/runit/1.d/anacron
run-parts: executing /etc/runit/1.d/cleanup-pids
Cleaning stale PID files
run-parts: executing /etc/runit/1.d/copy-env
run-parts: executing /etc/runit/1.d/letsencrypt
[Wed 01 Jan 2020 10:40:41 AM UTC] Domains not changed.
[Wed 01 Jan 2020 10:40:41 AM UTC] Skip, Next renewal time is: Tue Feb 25 00:52:11 UTC 2020
[Wed 01 Jan 2020 10:40:41 AM UTC] Add '--force' to force to renew.
[Wed 01 Jan 2020 10:40:41 AM UTC] Installing key to:/shared/ssl/discourse.example.com.key
[Wed 01 Jan 2020 10:40:41 AM UTC] Installing full chain to:/shared/ssl/discourse.example.com.cer
[Wed 01 Jan 2020 10:40:41 AM UTC] Run reload cmd: sv reload nginx
warning: nginx: unable to open supervise/ok: file does not exist
[Wed 01 Jan 2020 10:40:41 AM UTC] Reload error for :
[Wed 01 Jan 2020 10:40:42 AM UTC] Domains not changed.
[Wed 01 Jan 2020 10:40:42 AM UTC] Skip, Next renewal time is: Wed Jan  8 00:39:10 UTC 2020
[Wed 01 Jan 2020 10:40:42 AM UTC] Add '--force' to force to renew.
[Wed 01 Jan 2020 10:40:42 AM UTC] Installing key to:/shared/ssl/discourse.example.com_ecc.key
[Wed 01 Jan 2020 10:40:42 AM UTC] Installing full chain to:/shared/ssl/discourse.example.com_ecc.cer
[Wed 01 Jan 2020 10:40:42 AM UTC] Run reload cmd: sv reload nginx
warning: nginx: unable to open supervise/ok: file does not exist
[Wed 01 Jan 2020 10:40:42 AM UTC] Reload error for :
Started runsvdir, PID is 628
chgrp: invalid group: ‘syslog’
rsyslogd: imklog: cannot open kernel log (/proc/kmsg): Operation not permitted.
rsyslogd: activation of module imklog failed [v8.1901.0 try https://www.rsyslog.com/e/2145 ]
supervisor pid: 633 unicorn pid: 647

Redis DB를 flush해 보았지만 도움이 되지 않았습니다.
앱, Postgres, Redis를 각각 별도의 컨테이너로 분리해 두고 있습니다.
이 문제를 해결하는 방법에 대한 아이디어가 있을까요?

2

Sidekiq가 일시 중지된 상태이며, 작업 큐가 쌓이고 있습니까?

3

기본 큐에 2개의 작업이 표시되며, 모두 Jobs::VersionCheck입니다.
Redis DB를 flush한 후에는 완료 0개, 실패 0개, 대기 중 2개로 표시됩니다.

스케줄러 페이지에는 일부 작업이 대기 중이거나 실행 중인 것으로 보이지만, 이 작업들은 sidekiq 페이지의 통계에 반영되지 않습니다. 스케줄러 페이지의 모든 작업은 소요 시간이 비어 있거나 -1ms로 표시됩니다.

즉, 숫자가 쌓이지 않고 실제로 아무것도 변하지 않습니다.
sidekiq가 일시 정지 상태인지 어떻게 확인합니까?

4

최신 업데이트 후에도 같은 문제가 발생합니다. 재빌드를 통해 업데이트한 것 외에는 변경 사항이 없는데, 관리자 대시보드에서 sidekiq이 실행되지 않는다고 표시됩니다. postgres/redis는 컨테이너 하나에, 앱은 다른 컨테이너에 있으며, 모두 다시 시작해 보았습니다. 큐에는 몇백 개의 작업이 쌓여 있지만 아무것도 처리되지 않습니다.

EDIT1: 모든 큐를 비워 보았지만 문제가 해결되지도, 도움이 되지도 않았습니다. 큐가 다시 채워지는데도 여전히 처리되지 않습니다.

EDIT2: 이로 인한 다운타임이 발생하더라도 포럼을 재빌드해 보았지만 여전히 이 메시지가 나타납니다:

image
image1084×160 14.4 KB

그리고 /sidekiq에서 큐가 처리되지 않습니다. 2.4.0.beta7에서 2.4.0.beta9로 업데이트하기 전까지는 모두 정상적으로 작동하고 있었습니다.

EDIT3: 50기가바이트 이상의 여유 공간이 있습니다. 수동으로 백업을 실행해 보면(약 300메가바이트) 성공적으로 수행되며, sidekiq을 일시 정지했다가 재개한다고 표시되고 로그에는 오류가 보고되지 않지만, sidekiq은 여전히 실행되지 않는 것처럼 보입니다?

EDIT4: /logs에서 주목할 만한 로그는 반복적으로 나타나는 Sidekiq heartbeat test failed, restarting뿐입니다.

EDIT5: Redis는 정상적으로 실행되고 있는 것 같습니다. 적어도 로그 파일에는 할 일이 많지 않다고 계속 표시되고 있습니다… 그리고 명확히 하기 위해:

[3] pry(main)> Sidekiq.paused?
=> false

EDIT6: 조금 전에 큐를 비웠는데, 다시 10개의 작업이 큐에 쌓였지만 처리되지 않습니다.

EDIT7: 일반적인 프로젝트에서 sidekiq을 시작하는 일반적인 방법은 bundle exec sidekiq라는 것을 알게 되었고, 그래서 실행해 보겠습니다:

root@vps198273-forum:/var/www/discourse# bundle exec sidekiq
2020-01-06T05:10:18.814Z pid=31242 tid=gn383wxbu INFO: Booting Sidekiq 6.0.4 with redis options {:host=>"forum-data", :port=>6379, :namespace=>"sidekiq", :id=>"Sidekiq-server-PID-31242", :url=>nil}
You are connecting to Redis v3.0.6, Sidekiq requires Redis v4.0.0 or greater
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.4/lib/sidekiq/cli.rb:62:in `run'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.4/bin/sidekiq:12:in `<top (required)>'
/var/www/discourse/vendor/bundle/ruby/2.6.0/bin/sidekiq:23:in `load'
/var/www/discourse/vendor/bundle/ruby/2.6.0/bin/sidekiq:23:in `<top (required)>'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/cli/exec.rb:63:in `load'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/cli/exec.rb:63:in `kernel_load'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/cli/exec.rb:28:in `run'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/cli.rb:476:in `exec'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/vendor/thor/lib/thor.rb:399:in `dispatch'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/cli.rb:30:in `dispatch'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/vendor/thor/lib/thor/base.rb:476:in `start'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/cli.rb:24:in `start'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/exe/bundle:46:in `block in <top (required)>'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/friendly_errors.rb:123:in `with_friendly_errors'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/exe/bundle:34:in `<top (required)>'
/usr/local/bin/bundle:23:in `load'
/usr/local/bin/bundle:23:in `<main>'

You are connecting to Redis v3.0.6, Sidekiq requires Redis v4.0.0 or greater

음, 이건 흥미롭네요? 데이터 컨테이너를 재빌드해 보고 데이터에 손대는 것에 대한 공포로부터 기도해 보겠습니다, 하하…

EDIT8: Redis 5.0.5가 실행되고 있는 것 같습니다(왜 postgresql pubsub를 이 용도로 사용하지 않는 걸까요?). 이는 분명히 4.0.0 이상입니다… 재빌드가 완료되었고 포럼을 테스트해 보니 데이터가 여전히 있는 것 같으며, 스파이크가 나타났습니다!

image
image367×572 61.8 KB

해결된 것 같습니다! 이 게시글이 누군가에게 도움이 될 수도 있겠네요. 포럼에서 sidekiq이 보고한 오래된 redis에 대한 오류를 보여줬으면 좋았을 텐데, 아마도 그 로그들은 어디론가 사라진 것 같습니다. 어디서도 보이지 않았거든요. ^.^

5

정말 훌륭한 탐정活儿입니다. 다른 분들에게도 도움이 되길 바랍니다.

6

고대의 redis를 어떻게 구하셨나요? 표준이 아닌 설치 방법을 사용하고 계신 건가요?

7

멀티컨테이너 구성을 사용하고 있으며, redis를 재빌드한 적이 없습니다.
redis를 재빌드해 볼 것입니다.

UPD.
@OvermindDL1, 해결 방법 알려주셔서 감사합니다. redis 컨테이너를 재빌드한 후 이제 모든 것이 정상적으로 작동합니다.

Sidekiq는 백그라운드 작업 라이브러리로, redis에 의존합니다. 매우 최적화되고 성숙한 라이브러리이지만 redis 백엔드만 지원합니다.
또한 message_bus(discourse의 실시간 기능)도 내부적으로 redis를 사용한다고 생각합니다.

8

설명서대로 표준 도커 분리 컨테이너 설치를 사용했습니다(새로운 discourse 버전을 빌드한 후 중단 시간 없이 빠르게 전환할 수 있도록 하기 위해서요). 하지만 데이터 컨테이너에는 손을 대지 않았는데,Apparently redis가 거기서 실행되고 있는 것 같습니다. (redis가 메인 컨테이너에서 실행될 줄 알았는데, 메인 컨테이너에서 실행 중인 것을 찾지 못해 놀랐습니다.)

네, @arrowcircle 님과 정확히 같은 상황입니다. :slight_smile:

9

컨테이너 2개 구성을 사용하더라도 데이터 컨테이너를 다시 빌드해야 합니다. 최소한 연 1회 정기적으로 실행할 것을 권장합니다.

10

그렇다면 다운타임 없이 이 작업을 수행할 수 있는 방법이 있을까요? 처음부터 분리한 이유가 바로 그거였거든요.

11

다운타임이 전혀 없기를 원하신다면 리플리카 Redis와 리플리카 데이터베이스를 실행해야 합니다. 페일오버 시에도 짧은 읽기 전용(read-only) 단계가 발생할 것입니다.

네, 이러한 것들은 모두 가능하지만 인프라 팀을 채용해야 합니다.

12

여기 있는 모든 것은 오픈소스이며, 돈은 전혀 없습니다. ^.^;