AlmaLinux 8.9(カーネル4.18.0-513.9.1.el8_9.x86_64)を実行しているThinkSystem SR630 V2サーバーに影響を与える重要な問題について、専門家のアドバイスを求めようと書いています。同じオペレーティングシステムとカーネルバージョンで2つの仮想マシンをホストします。
質問:
さまざまな地域(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状態に停止しているため、Webアプリケーションが応答しなくなります。
- 詳細:
- 影響を受けるスレッドは、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のテーブルロックによりWebアプリケーションが応答しなくなりました。
- MySQLを再起動すると、ゾンビプロセスが発生する可能性があります。
- MySQLバックアップも0バイトのファイルで停止し、リソースアクセスの問題を示します。
- 技術の詳細(参考用):
- MySQLプロセス(PID 1282)が死んだゾンビ状態にあります。
- 別のサービスプロセス(PID 604275)もゾンビプロセスです。
- SIGCHLDを使用してゾンビプロセスを終了しようとして失敗しました。
- 重要な点:さらなる調査は、テーブルロックが唯一の原因であるという疑問を提起し、より広範なリソースアクセスの問題を指摘しました。
イベント3
- 質問:
- Webアプリケーションが応答しなくなり、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
- 質問:
- Webアプリケーションが応答しなくなり、両方のプロセスが動作不能(ゾンビ)状態にあることがわかりました。これは、親プロセスによる適切なクリーンアップなしで異常終了したことを示します。
- 技術の詳細(参考用):
- 「[service_process]」(プロセスID 261224および950658)で識別された両方のプロセスは、その親プロセスが終了状態を収集していないため、古い状態で停止しました。
- これは、プロセス管理または親プロセスと子プロセス間の通信に潜在的な問題があることを示しています。