Discourse 업데이트가 계속 실패합니다

코어 덤프와 잘못된 명령어는 하위 레벨(CPU, 메모리)에서 문제가 발생하고 있음을 나타냅니다.

저는 하드웨어 전문가가 아니지만, 이 CPU는 12년 전에 출시된 제품이며 너무 오래되어 최신 CPU를 전제로 컴파일된 코드를 실행하려는 시도로 인해 문제가 생기는 것 같다는 의심이 듭니다.

이 부분은 고려해 보았지만, 지난 3년간 문제가 없이 잘 작동해 왔는데, 스택 내에서 갑자기 더 새로운 명령어가 필요하도록 업데이트된 것이 무엇일까요? (또한, 어떤/어떤 명령어인가요?)

FEATURE: Add support for clear_every parameter in Redis backend (#309) · discourse/message_bus@1baa1ea · GitHub가 Redis 내에서 다른 동작을 유발하고 있는 것일까요? :thinking:

또한, 지난 금요일에 주요 버전 업그레이드가 무리 없이 진행되었고, 주말 내내 아무 문제 없이 작동했습니다. 일요일에도 업데이트를 성공적으로 수행했습니다. 만약 이해할 수 있는 부분인 CPU가 원인이라면, 주요 버전 업그레이드 시에도 이 오류가 나타났을 것입니다.

하지만, 월요일 이후에 어떤 변화가 있었을 수도 있습니다…

가능합니다. 메시지 버스 코드 내의 JSON 파싱 루틴에서 크래시가 발생하고 있지만, 언급하신 그 변경 사항은 4개월 이상 지난 것이므로 원인이 될 가능성은 낮습니다.

-- C level backtrace information -------------------------------------------
/usr/local/lib/libruby.so.2.7(rb_vm_bugreport+0x50a) [0x7f30fc64839a] vm_dump.c:755
[0x7f30fc4b9b47]
/usr/local/lib/libruby.so.2.7(sigill+0x3b) [0x7f30fc5c4f0b] signal.c:962
/lib/x86_64-linux-gnu/libc.so.6(0x7f30fc283d60) [0x7f30fc283d60]
/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/oj-3.13.15/lib/oj/oj.so(oj_parse2+0x4f9) [0x7f30f3a68339] /usr/lib/gcc/x86_64-linux-gnu/10/include/smmintrin.h:649

I, [2022-07-05T10:03:30.513303 #1]  INFO -- : > cd /var/www/discourse && su discourse -c 'bundle exec rake db:migrate'
/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/message_bus-4.2.0/lib/message_bus/codec/json.rb:11: [BUG] Illegal instruction at 0x00007f30f3a68339
ruby 2.7.6p219 (2022-04-12 revision c9c2245c0a) [x86_64-linux]

-- Control frame information -----------------------------------------------
c:0030 p:---- s:0162 e:000161 CFUNC  :parse
c:0029 p:0013 s:0157 e:000156 METHOD /var/www/discourse/vendor/bundle/ruby/2.7.0/gems/message_bus-4.2.0/lib/message_bus/codec/json.rb:11
c:0028 p:0037 s:0152 e:000151 METHOD /var/www/discourse/vendor/bundle/ruby/2.7.0/gems/message_bus-4.2.0/lib/message_bus.rb:648
c:0027 p:0020 s:0144 e:000143 BLOCK  /var/www/discourse/vendor/bundle/ruby/2.7.0/gems/message_bus-4.2.0/lib/message_bus.rb:766
c:0026 p:0082 s:0135 e:000134 BLOCK  /var/www/discourse/vendor/bundle/ruby/2.7.0/gems/message_bus-4.2.0/lib/message_bus/backends/redis.rb:330
c:0025 p:0024 s:0130 e:000129 BLOCK  /var/www/discourse/vendor/bundle/ruby/2.7.0/gems/redis-4.5.1/lib/redis/subscribe.rb:46
c:0024 p:0034 s:0124 e:000123 BLOCK  /var/www/discourse/vendor/bundle/ruby/2.7.0/gems/redis-4.5.1/lib/redis/client.rb:183 [FINISH]

네… 그렇다면 일요일에는 이미 적용되어 있어야 했을 텐데요. :pensive:

로그를 살펴보니, Redis를 시작하려고 할 때 이미 다른 Redis 인스턴스가 실행 중인 것 같습니다.
이것이 문제의 원인일 수 있을까요?

102:C 05 Jul 2022 09:53:34.597 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
102:C 05 Jul 2022 09:53:34.597 # Redis version=6.2.6, bits=64, commit=00000000, modified=0, pid=102, just started
102:C 05 Jul 2022 09:53:34.597 # Configuration loaded
102:M 05 Jul 2022 09:53:34.598 * monotonic clock: POSIX clock_gettime
102:M 05 Jul 2022 09:53:34.599 * Running mode=standalone, port=6379.
102:M 05 Jul 2022 09:53:34.599 # Server initialized
102:M 05 Jul 2022 09:53:34.599 # WARNING overcommit_memory is set to 0! Background save may fail under low memory condition. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
102:M 05 Jul 2022 09:53:34.599 * Loading RDB produced by version 6.2.6
102:M 05 Jul 2022 09:53:34.599 * RDB age 1972 seconds
102:M 05 Jul 2022 09:53:34.599 * RDB memory usage when created 60.60 Mb
102:M 05 Jul 2022 09:53:34.949 # Done loading RDB, keys loaded: 8005, keys expired: 9.
102:M 05 Jul 2022 09:53:34.950 * DB loaded from disk: 0.351 seconds
102:M 05 Jul 2022 09:53:34.950 * Ready to accept connections
129:C 05 Jul 2022 09:53:45.056 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
129:C 05 Jul 2022 09:53:45.056 # Redis version=6.2.6, bits=64, commit=00000000, modified=0, pid=129, just started
129:C 05 Jul 2022 09:53:45.056 # Configuration loaded
129:M 05 Jul 2022 09:53:45.057 * monotonic clock: POSIX clock_gettime
129:M 05 Jul 2022 09:53:45.057 # Warning: Could not create server TCP listening socket *:6379: bind: Address already in use
129:M 05 Jul 2022 09:53:45.057 # Failed listening on port 6379 (TCP), aborting.
102:signal-handler (1657015415) Received SIGTERM scheduling shutdown...
102:M 05 Jul 2022 10:03:35.245 # User requested shutdown...
102:M 05 Jul 2022 10:03:35.245 * Saving the final RDB snapshot before exiting.
102:M 05 Jul 2022 10:03:39.882 * DB saved on disk
102:M 05 Jul 2022 10:03:39.882 # Redis is now ready to exit, bye bye...

launcher rebuild app에서는 꽤 일반적인 현상입니다. (적어도 제가 아는 한) 아무런 영향을 미치지 않습니다.

코드 경로도 특정 데이터가 존재하거나 부재할 때 트리거될 수 있습니다. 문제가 되는 코드는 이미 존재했지만 실행되지 않았을 수 있습니다.

최근 커밋 세트에서 유사 이분법(quasi-bisecting)을 시도해 보고, 특정 최근 변경 사항으로 범위를 좁혀볼 생각입니다. 이 작업에는 “시간이 좀 걸릴” 것입니다… :sweat_smile:

수정:

자, 불법 명령(illegal instruction)을 유발하는 첫 번째 잘못된 커밋은 Build(deps): Bump oj from 3.13.14 to 3.13.15 (#17309) · discourse/discourse@4c69619 · GitHub 이며, 이는 Fix NaN object dump issue · ohler55/oj@f0122cf · GitHub 와 연결되어 있습니다.

이전 커밋들도 빌드에 실패하지만, 다른 문제(이것도 일시적인 것처럼 보이지만…)가 발생합니다:

I, [2022-07-05T12:14:35.377926 #1]  INFO -- : > cd /var/www/discourse && su discourse -c 'bundle exec rake db:migrate'                                                          
102:M 05 Jul 2022 12:14:44.308 * 100 changes in 300 seconds. Saving...                                                                                                          
102:M 05 Jul 2022 12:14:44.312 * Background saving started by pid 709                                                                                                           
709:C 05 Jul 2022 12:14:45.166 * DB saved on disk                                                                                                                               
709:C 05 Jul 2022 12:14:45.169 * RDB: 1 MB of memory used by copy-on-write                                                                                                      
102:M 05 Jul 2022 12:14:45.217 * Background saving terminated with success                                                                                                      
I, [2022-07-05T12:14:46.192386 #1]  INFO -- :                                                                                                                                   
I, [2022-07-05T12:14:46.193317 #1]  INFO -- : > cd /var/www/discourse && su discourse -c 'bundle exec rake themes:update assets:precompile'                                     
                                                                                                                                                                                
Missing yarn packages:                                                                                                                                                          
Package: ember-cli-deprecation-workflow                                                                                                                                         
  * Specified: ^2.1.0                                                                                                                                                           
  * Installed: (not installed)                                                                                                                                                  
                                                                                                                                                                                
Run `yarn` to install missing dependencies.                                                                                                                                     
                                                                                                                                                                                
                                                                                                                                                                                
                                                                                                                                                                                
Stack Trace and Error Report: /tmp/error.dump.ccfa3d8342a442ee6860db37ce7c7330.log                                                                                              
An error occurred in the constructor for ember-cli-dependency-checker at /var/www/discourse/app/assets/javascripts/node_modules/ember-cli-dependency-checker                    
                                                                                                                                                                                
error Command failed with exit code 1.

좋은 지적입니다. 실제로 oj gem에서 크래시가 발생하고 있네요.

3.13.15 버전에는 성능 향상을 위해 SSE 4.2 명령어를 사용하도록 변경한 이 커밋도 포함되어 있습니다. 그리고 이 명령어들은 AMD Opteron 41xx 프로세서에서 지원되지 않습니다.

따라서 다시

의 상황으로 돌아갔습니다.

개인적 의견으로는, gem 저자가 이 부분을 컴파일 타임 결정으로 만든 것이 실망스럽습니다.

좋네요. oj 변경 로그에 언급되지 않은 추가적인 변경 사항이 있네요… :grin:

그래서, 이 gem이 설치 과정에서 네이티브 컴파일을 수행하지 않는다면(즉, OJ_USE_SSE4_2를 통해 작동하도록 유도할 수 있다면), 서버 이전이 필요해 보입니다… :expressionless:

수정: 이 gem은 사전 컴파일된 객체를 배포하지 않으므로 이 방법은 작동할 것 같습니다. 그렇다면 다음 질문은, SSE4.2를 지원하지 않는 시스템에서 왜 SSE4.2로 컴파일되는지입니다.

현재 기본 이미지에는 3.13.14 버전이 포함되어 있어 시스템에서 컴파일되고 있습니다.

해당 커밋의 벤치마크 스크립트를 사용하여 오류를 재현해 볼 수 있습니다:

○ → docker run --rm -it -u discourse discourse/base:2.0.20220621-0049 bash
discourse@313d7af3be39:/$ cd
discourse@313d7af3be39:~$ gem install --user pry benchmark-ips oj
…
Successfully installed oj-3.13.15
5 gems installed
discourse@313d7af3be39:~$ /home/discourse/.local/share/gem/ruby/2.7.0/bin/pry
[1] pry(main)> require 'benchmark/ips'
require 'oj'

def json(string)
  "\"#{string}\""
end

Benchmark.ips do |x|
  x.warmup = 5
  x.time = 20

  json_0   = json('a' *   0)
  json_64  = json('a' *  64)
  json_128 = json('a' * 128)

  x.report('Oj.load   [0]') { Oj.load(json_0) }
  x.report('Oj.load  [64]') { Oj.load(json_64) }
  x.report('Oj.load [128]') { Oj.load(json_128) }
end;

또는 다음 명령을 사용하여 문제의 명령어가 사용되어 컴파일되었는지 확인할 수 있습니다:

discourse@313d7af3be39:~$ objdump -d /home/discourse/.local/share/gem/ruby/2.7.0/gems/oj-3.13.15/lib/oj/oj.so | grep -C3 pcmpestri
   2e32b:	0f 82 b5 03 00 00    	jb     2e6e6 <oj_parse2+0x8a6>
   2e331:	66 0f 6f 05 77 d6 01 	movdqa 0x1d677(%rip),%xmm0        # 4b9b0 <exp_plus+0x330>
   2e338:	00 
   2e339:	66 0f 3a 61 07 00    	pcmpestri $0x0,(%rdi),%xmm0
   2e33f:	83 f9 10             	cmp    $0x10,%ecx
   2e342:	74 dc                	je     2e320 <oj_parse2+0x4e0>
   2e344:	48 63 c9             	movslq %ecx,%rcx

그렇다면 이는 아마도 oj gem 프로젝트에 보고해야 할 문제일 것입니다.

이 문제를 좀 더 자세히 살펴보고 싶긴 하지만, 1) 당분간은 더 이상의 다운타임을 피하고 싶습니다(위 내용은 다운타임이 발생하지 않는다는 것을 알고 있지만, 다른 것들을 시도해 보게 될 수 있습니다) 그리고 2) 이 부분이 변경될 때:

3.13.15로 변경되고 Discourse 기본 이미지가 동일한 최소 CPU 마이크로아키텍처 요구 사항을 상속하게 되면, 현재 서버는 어쨌든 지속 가능하지 않을 것입니다(예: 코드 전 훅의 일부로 젠을 별도로 (재)설치하는 것과 같은 우회 방법이 있을 수 있지만, 대부분의 사람들에게는 다소 번거로운 작업일 것이라 추측합니다).

또한 하드웨어 지원의 적절한 마감 시점이 어쨌든 무엇이어야 하는지에 대한 질문도 제기됩니다. 32비트 CPU 지원을 기대하는 것은 합리적이지 않으므로, SSE4.2가 현대 소프트웨어에 대한 합리적인 "새로운 최소 요구 사항"이 될 수 있습니다.

맞습니다. 이미 내부적으로 이 문제를 제기했습니다.

:+1:

안녕하세요!

이 문제를 확인해 주셔서 감사합니다. 저는 Intel Atom N2800 (2011년 말 제품)에서도 동일한 문제를 겪고 있습니다.
이 문제를 우회할 수 있는 방법이 있을까요? 아니면 당분간 더 새로운 하드웨어로 이전하는 것만이 유일한 해결책일까요?

감사합니다,

오늘 업데이트를 진행하면서 이제 포럼이 완전히 마비되었습니다. CPU의 향후 폐기 예정에 대한 경고는 전혀 본 적이 없는데, 이렇게 갑자기 이런 일이 벌어지다니… 정말 좋지 않습니다. 일관성을 위해 사용 가능한 모든 서버가 동일한 구성을 사용하며, 모두 같은 CPU를 사용하고 있습니다.

AMD Athlon™ II X2 B22 Processor

이런 경제 상황에서는 새 서버를 급히 구매하고 설정하는 등의 조치는 현실적으로 어렵습니다. 시간이 있어도 마찬가지입니다.

이 상황이 더 명확해질 때까지 이 업데이트를 되돌릴 수 있는 방법이 있을까요? 포럼이 다운되어 있어 지금 사용자에게 연락조차 할 수 없습니다. 감사합니다.

Docker 배포 방법을 사용하고 있다면, 재시작할 수 있는 이전 컨테이너가 있을 수 있습니다 (예: docker images 및/또는 docker ps -a를 확인하세요).

app.yml 파일을 편집하여 버전을 변경 전 커밋으로 설정한 후 다시 빌드하면, Discourse 인스턴스를 빌드하는 데 사용되는 커밋을 오버라이드할 수도 있습니다:

params:
  version: adb7fa5e2fc51308efc9fc4ee57ecb1c15a85cfa

이후 업데이트를 수행하면 Discourse가 다시 깨질 수 있으며, 이후에 보안 업데이트가 출시되었기 때문에 이는 이상적이지 않습니다 (대부분의 인스턴스에 대해 악용 가능성이 매우 제한적인 것으로 보이지만).

한 가지 옵션(아직 시도하지 않은 방법)은 oj 제보를 별도로 설치하고, 올바른 CPU 기능(또는 그 부재)으로 컴파일이 트리거되기를 기다리는 것입니다.

저는 app.yml에서 이것을 시도할 계획이었습니다:

hooks:
  before_code:
    - exec:
        cmd:
          - gem install oj

하지만 더 이상의 포럼 다운타임은 감당할 여유가 없습니다.

해당 보안 업데이트는 제가 공유 호스팅 환경이 아니므로 저에게는 관련이 없어 보입니다. docker info를 어떻게 해석해야 할지 모르겠습니다. ps 출력 결과는 다음과 같습니다:

37c258b23221 local_discourse/app “/sbin/boot” 3 months ago Exited (7) 3 hours ago

이미지 목록은 다음과 같습니다:

REPOSITORY            TAG                 IMAGE ID       CREATED         SIZE
discourse/base        2.0.20220621-0049   a44ca4f67972   3 weeks ago     2.65GB
local_discourse/app   latest              b5f2a8a39709   3 months ago    3.53GB
discourse/base        2.0.20220413-0411   ab71a5d97460   3 months ago    2.81GB
<none>                <none>              58ba7d1c8d7a   3 months ago    3.74GB
discourse/base        2.0.20220224-2005   cd112601450a   4 months ago    2.84GB
<none>                <none>              d9cf1feb92fd   6 months ago    3.19GB
<none>                <none>              d53ee33f6fe1   6 months ago    3.19GB
<none>                <none>              14f79500c49c   6 months ago    3.19GB
<none>                <none>              edff9b614f46   6 months ago    3.19GB
<none>                <none>              e2348b41f937   6 months ago    3.19GB
<none>                <none>              42f6511b414c   6 months ago    3.19GB
<none>                <none>              3086f92af2fe   6 months ago    3.19GB
<none>                <none>              6ada029723ba   6 months ago    3.19GB
<none>                <none>              ca61149580d4   6 months ago    3.19GB
<none>                <none>              ce5ae3bb62ac   6 months ago    3.19GB
<none>                <none>              e9a5c1b1aed4   6 months ago    3.19GB
<none>                <none>              6bb94ce1e01f   6 months ago    3.19GB
<none>                <none>              e1df4acbd927   6 months ago    3.19GB
<none>                <none>              7e05a0b160c5   6 months ago    3.19GB
<none>                <none>              979926f28a73   6 months ago    3.19GB
<none>                <none>              d055f9b01556   6 months ago    3.19GB
<none>                <none>              aa0c779093dc   6 months ago    3.19GB
discourse/base        2.0.20211118-0105   b6cc7cf8974a   7 months ago    2.58GB
discourse/base        2.0.20210528-1735   482386bf57af   13 months ago   2.36GB
<none>                <none>              e6011d2b206c   14 months ago   2.69GB
discourse/base        2.0.20210415-1332   30e4746e631e   15 months ago   2.23GB
<none>                <none>              8066ac13b8c3   17 months ago   2.45GB
discourse/base        2.0.20201221-2020   c0704d4ce2b4   18 months ago   2.11GB
<none>                <none>              043da6b3335d   2 years ago     2.4GB
discourse/base        2.0.20200429-2110   dc919e1dae2c   2 years ago     2.13GB
<none>                <none>              ff15472f4794   2 years ago     2.79GB
discourse/base        2.0.20191013-2320   09725007dc9e   2 years ago     2.3GB
<none>                <none>              f65391a062f0   2 years ago     2.62GB
discourse/base        2.0.20190901-2315   10f636afbeaf   2 years ago     2.29GB
<none>                <none>              6944d06786b4   2 years ago     2.31GB
discourse/base        2.0.20190625-0946   2b3a5b47565f   3 years ago     1.93GB
<none>                <none>              60b39deba7d2   3 years ago     2.3GB
discourse/base        2.0.20190505-2322   ed87227f60d2   3 years ago     1.91GB
<none>                <none>              cc5c0e56298c   3 years ago     2.38GB
discourse/base        2.0.20190321-0122   7db99586b5b5   3 years ago     1.97GB
<none>                <none>              b19f9a483788   3 years ago     2.27GB
discourse/base        2.0.20190217        9c24db193c37   3 years ago     1.92GB
hello-world           latest              fce289e99eb9   3 years ago     1.84kB
<none>                <none>              614db6988e9c   3 years ago     2.25GB
<none>                <none>              729b196da862   3 years ago     2.25GB
<none>                <none>              80584ec5ec01   3 years ago     2.25GB
<none>                <none>              0e2481aefed8   3 years ago     2.25GB
<none>                <none>              725d0c17a6bb   3 years ago     2.25GB
<none>                <none>              220bed95d236   3 years ago     2.25GB
<none>                <none>              fca469dba597   3 years ago     2.25GB
<none>                <none>              edab31d0ffce   3 years ago     2.25GB
<none>                <none>              dbacaff2d35e   3 years ago     2.25GB
<none>                <none>              3d6a0453da1d   3 years ago     2.25GB
<none>                <none>              fbf0529eb303   3 years ago     2.25GB
<none>                <none>              7a45443ae44c   3 years ago     2.25GB
<none>                <none>              ad90d7f42416   3 years ago     2.25GB
<none>                <none>              d61ea07d6084   3 years ago     2.25GB
<none>                <none>              d393fd8b4de0   3 years ago     2.25GB
discourse/base        2.0.20181031        ea31cd77735a   3 years ago     1.88GB


./launcher start app를 시도해 볼 수 있을까요?