AlmaLinux 8.9(커널 4.18.0-513.9.1.el8_9.x86_64)를 실행하는 ThinkSystem SR630 V2 서버에 영향을 미치는 중요한 문제에 대해 전문가의 조언을 구하고자 글을 쓰고 있습니다. 동일한 운영 체제와 커널 버전에서 두 개의 가상 머신을 호스팅합니다.
질문:
다양한 지역(MySQL, Java, QXL/VRAM)의 여러 프로세스가 비정상 종료(좀비 상태) 및 정지 상태(D 상태)를 경험하고 있습니다. 일관된 패턴이 없기 때문에 근본 원인을 정확히 찾아내는 것이 어려워지며, 이는 개별 애플리케이션 문제가 아닌 시스템 불안정을 나타냅니다.
취해야 할 문제 해결 단계:
- 최신 UEFI 펌웨어가 검증되었으며 Lenovo에 RAID 어댑터 업데이트가 있는지 확인할 것입니다.
- BMC 및 XClarity Provision Manager 업데이트는 기여할 것 같지 않지만 확인되었습니다.
- 모든 서버에서 사용 가능한 커널과 패키지를 업그레이드하는 것이 좋습니다.
질문:
- 알려진 커널 버그: 커널 4.18.0-513.9.1.el8_9에 알려진 버그가 있거나 SR630 V2 커널 모듈과의 호환성 문제가 있습니까?
- 좀비 프로세스 분석: 스택 추적 외부에서 좀비 프로세스(프로세스가 종료됨)의 원인을 확인하기 위해 어떤 도구/방법을 사용할 수 있습니까?
- D-상태 프로세스 분석: strace 및 gdb가 D-상태 프로세스와 함께 사용되지 못하게 하는 권한 문제를 극복하는 방법은 무엇입니까? 어떤 대체 디버깅 방법을 사용할 수 있습니까?
- 메모리 덤프: D 상태의 프로세스의 메모리 덤프를 추출하는 방법이 있나요?
- 하드웨어 테스트: 메모리나 디스크 문제로 비슷한 문제를 겪은 사람이 있습니까? 특정 하드웨어 테스트를 추천해 주실 수 있나요?
추가 정보:
- 현재 nmon을 통해 통계를 수집하고 있습니다.
- 시스템 로그(/var/log/messages)에 새로운 오류가 나타나지 않습니다.
아래에 사건 세부사항에 대한 요약을 제공했지만 요청 시 더 많은 정보를 제공받을 수 있습니다.
이벤트 1
- 질문:
- 커널 작업자 스레드(kworker/6:24+ev)가 D 상태에 멈춰 있기 때문에 웹 애플리케이션이 응답하지 않게 됩니다.
- 세부 사항:
- 영향을 받는 스레드는 I/O, 타이머, 프로세스 관리 등 다양한 백그라운드 작업을 담당합니다.
- gdb 또는 strace를 사용하여 스레드를 디버깅하려는 시도가 실패했습니다.
- 스레드의 스택 추적을 분석한 결과 QXL 그래픽 장치 펜스를 기다리고 있는 것으로 나타났습니다.
- 시스템 로그는 QXL 그래픽 드라이버가 비디오 RAM(VRAM)에 버퍼 개체(BO)를 할당하지 못했음을 확인합니다.
- 핵심:
- 이 사건은 QXL 그래픽 드라이버와 관련된 것으로 보이지만 이전 사건은 이 사건과 관련이 없었으며 더 깊은 근본적인 문제를 암시합니다.
# cat /proc/719494/stack
[<0>] qxl_fence_wait+0x109/0x160 [qxl]
[<0>] dma_fence_wait_timeout+0x4e/0x120
[<0>] dma_resv_wait_timeout+0x67/0xc0
[<0>] ttm_bo_wait_ctx+0x39/0x50 [ttm]
[<0>] qxl_bo_move+0x32/0xa0 [qxl]
[<0>] ttm_bo_handle_move_mem+0xb9/0x140 [ttm]
[<0>] ttm_mem_evict_first+0x2bb/0x500 [ttm]
[<0>] ttm_bo_mem_space+0x1d1/0x220 [ttm]
[<0>] ttm_bo_validate+0xa0/0x120 [ttm]
[<0>] ttm_bo_init_reserved+0x147/0x170 [ttm]
[<0>] qxl_bo_create+0x158/0x200 [qxl]
[<0>] qxl_alloc_bo_reserved+0x3e/0xb0 [qxl]
[<0>] qxl_image_alloc_objects+0x69/0x120 [qxl]
[<0>] qxl_draw_dirty_fb+0x178/0x450 [qxl]
[<0>] qxl_framebuffer_surface_dirty+0xf8/0x1d0 [qxl]
[<0>] drm_fbdev_fb_dirty+0x125/0x350 [drm_kms_helper]
[<0>] drm_fb_helper_damage_work+0x86/0x160 [drm_kms_helper]
[<0>] process_one_work+0x1d3/0x390
[<0>] worker_thread+0x1f9/0x390
[<0>] kthread+0x134/0x150
[<0>] ret_from_fork+0x1f/0x40
dmesg | grep qxl
[831639.144553] [drm:qxl_alloc_bo_reserved [qxl]] *ERROR* failed to allocate VRAM BO
[831654.501399] qxl 0000:00:01.0: object_init failed for (4096, 0x00000001)
[831654.502061] [drm:qxl_alloc_bo_reserved [qxl]] *ERROR* failed to allocate VRAM BO
[831669.861572] qxl 0000:00:01.0: object_init failed for (4096, 0x00000001)
[831669.862240] [drm:qxl_alloc_bo_reserved [qxl]] *ERROR* failed to allocate VRAM BO
[831685.221761] qxl 0000:00:01.0: object_init failed for (4096, 0x00000001)
[831685.222435] [drm:qxl_alloc_bo_reserved [qxl]] *ERROR* failed to allocate VRAM BO
[831700.581990] qxl 0000:00:01.0: object_init failed for (4096, 0x00000001)
[831700.582679] [drm:qxl_alloc_bo_reserved [qxl]] *ERROR* failed to allocate VRAM BO
[831715.942106] qxl 0000:00:01.0: object_init failed for (4096, 0x00000001)
[831715.942783] [drm:qxl_alloc_bo_reserved [qxl]] *ERROR* failed to allocate VRAM BO
[831731.302242] qxl 0000:00:01.0: object_init failed for (4096, 0x00000001)
[831731.302909] [drm:qxl_alloc_bo_reserved [qxl]] *ERROR* failed to allocate VRAM BO
[831746.662426] qxl 0000:00:01.0: object_init failed for (4096, 0x00000001)
perf record -g -p 719494
perf report
Samples: 55 of event 'cpu-clock:pppH', Event count (approx.): 13750000
Children Self Command Shared Object Symbol
+ 100.00% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] ret_from_fork
+ 100.00% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] kthread
+ 100.00% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] worker_thread
+ 100.00% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] process_one_work
+ 100.00% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] drm_fb_helper_damage_work
+ 100.00% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] drm_fbdev_fb_dirty
+ 52.73% 52.73% kworker/6:24+ev [kernel.kallsyms] [k] memcpy_erms
+ 47.27% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] qxl_framebuffer_surface_dirty
+ 47.27% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] qxl_draw_dirty_fb
+ 47.27% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] qxl_alloc_bo_reserved
+ 45.45% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] qxl_image_alloc_objects
+ 25.45% 1.82% kworker/6:24+ev [kernel.kallsyms] [k] vprintk_emit
+ 23.64% 21.82% kworker/6:24+ev [kernel.kallsyms] [k] console_unlock
+ 20.00% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] qxl_bo_create
+ 20.00% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] ttm_bo_init_reserved
+ 16.36% 1.82% kworker/6:24+ev [kernel.kallsyms] [k] __drm_err
+ 14.55% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] printk
+ 12.73% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] ttm_bo_validate
+ 12.73% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] ttm_bo_mem_space
+ 12.73% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] ttm_mem_evict_first
+ 12.73% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] ttm_bo_handle_move_mem
+ 12.73% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] qxl_bo_move
+ 12.73% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] ttm_bo_wait_ctx
+ 12.73% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] dma_resv_wait_timeout
+ 12.73% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] dma_fence_wait_timeout
+ 12.73% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] qxl_fence_wait
+ 10.91% 0.00% kworker/6:24+ev [kernel.kallsyms] [k] qxl_bo_create.cold.9
이벤트 2
- 질문:
- 처음에는 MySQL의 테이블 잠금으로 인해 웹 애플리케이션이 응답하지 않게 되었습니다.
- MySQL을 다시 시작하면 좀비 프로세스가 발생할 수 있습니다.
- MySQL 백업도 0바이트 파일에 멈춰 리소스 액세스 문제를 나타냅니다.
- 기술 세부정보(참고용):
- MySQL 프로세스(PID 1282)가 죽은 좀비 상태에 있습니다.
- 또 다른 서비스 프로세스(PID 604275)도 좀비 프로세스입니다.
- SIGCHLD를 사용하여 좀비 프로세스를 종료하려는 시도가 실패했습니다.
- 핵심 사항: 추가 조사를 통해 테이블 잠금이 유일한 원인이라는 의심이 제기되어 더 광범위한 리소스 액세스 문제가 지적되었습니다.
이벤트 3
- 질문:
- 웹 애플리케이션이 응답하지 않게 되고 Java 프로세스가 사용 가능한 스택 추적이 없는 D 상태에 멈춰 잠재적인 커널 수준 또는 프로세스 손상 문제를 나타냅니다.
- 핵심:
- 메모리 액세스 문제: "RIP 0x7fdd7e72a432에서 opcode 바이트에 액세스할 수 없습니다"라는 오류 메시지는 커널이 지정된 메모리 주소에서 명령어 바이트를 읽을 수 없음을 나타내며, 이는 메모리 관련 문제를 나타냅니다.
- 커널 기능 관련: 프로세스 예약과 관련된 로그에 커널 기능이 존재하며 시스템 호출 또는 프로세스 종료 중 잠재적인 문제에 대한 종료 힌트가 있습니다.
dmesg 로그
[Thu Jan 18 08:49:42 2024] RIP: 0033:0x7fdd7e72a45c
[Thu Jan 18 08:49:42 2024] Code: Unable to access opcode bytes at RIP 0x7fdd7e72a432.
[Thu Jan 18 08:49:42 2024] RSP: 002b:00007fdd663113e0 EFLAGS: 00000246 ORIG_RAX: 00000000000000ca
[Thu Jan 18 08:49:42 2024] RAX: fffffffffffffe00 RBX: 00007fdd30000b60 RCX: 00007fdd7e72a45c
[Thu Jan 18 08:49:42 2024] RDX: 0000000000000000 RSI: 0000000000000080 RDI: 00007fdd30000b8c
[Thu Jan 18 08:49:42 2024] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
[Thu Jan 18 08:49:42 2024] R10: 0000000000000000 R11: 0000000000000246 R12: 00007fdd78ded828
[Thu Jan 18 08:49:42 2024] R13: 0000000000000003 R14: 0000000000000000 R15: 00007fdd30000b8c
[Thu Jan 18 08:49:42 2024] task:java state:D stack:0 pid:2527 ppid:1 flags:0x80004084
[Thu Jan 18 08:49:42 2024] Call Trace:
[Thu Jan 18 08:49:42 2024] __schedule+0x2d1/0x870
[Thu Jan 18 08:49:42 2024] schedule+0x55/0xf0
[Thu Jan 18 08:49:42 2024] do_exit+0x250/0xb10
[Thu Jan 18 08:49:42 2024] do_group_exit+0x3a/0xa0
[Thu Jan 18 08:49:42 2024] get_signal+0x141/0x880
[Thu Jan 18 08:49:42 2024] ? do_futex+0x143/0x4e0
[Thu Jan 18 08:49:42 2024] do_signal+0x36/0x690
[Thu Jan 18 08:49:42 2024] ? __x64_sys_futex+0x14e/0x200
[Thu Jan 18 08:49:42 2024] ? syscall_trace_enter+0x1ff/0x2d0
[Thu Jan 18 08:49:42 2024] ? __x64_sys_futex+0x14e/0x200
[Thu Jan 18 08:49:42 2024] exit_to_usermode_loop+0x89/0x100
[Thu Jan 18 08:49:42 2024] do_syscall_64+0x19c/0x1b0
[Thu Jan 18 08:49:42 2024] entry_SYSCALL_64_after_hwframe+0x61/0xc6
[Thu Jan 18 08:49:42 2024] RIP: 0033:0x7fdd7e72a45c
[Thu Jan 18 08:49:42 2024] Code: Unable to access opcode bytes at RIP 0x7fdd7e72a432.
이벤트 4
- 질문:
- 웹 애플리케이션이 응답하지 않게 되었고 두 프로세스가 작동 불능(좀비) 상태에 있는 것으로 발견되었습니다. 이는 상위 프로세스에 의한 적절한 정리 없이 비정상적으로 종료되었음을 나타냅니다.
- 기술 세부정보(참고용):
- "[service_process]"(프로세스 ID 261224 및 950658)로 식별된 두 프로세스 모두 해당 상위 프로세스가 종료 상태를 수집하지 않았기 때문에 오래된 상태에 멈췄습니다.
- 이는 프로세스 관리 또는 상위 프로세스와 하위 프로세스 간의 통신에 잠재적인 문제가 있음을 나타냅니다.