printk死鎖是指在使用Linux內核中的printk函數打印日志時，由于某種原因導致系統中兩個或多個線程相互等待對方釋放資源而無法繼續執行的情況。printk死鎖會影響系統應用程序和業務的正常運行，最終觸發內核宕機，所以預防和及時解決printk死鎖對于維持系統穩定性和可靠性至關重要。本文介紹Alibaba Cloud Linux系統出現printk死鎖導致系統宕機的原因及解決方案。
問題描述
在使用Alibaba Cloud Linux發生內核宕機時，分析vmcore文件存在以下現象：
當系統發生宕機時，會生成轉儲文件vmcore，您可以通過查看該文件獲取宕機時的內核日志，并根據其中的calltrace信息（通常以"Call Trace:"開頭）來定位問題的發生位置，分析宕機原因，從而進行修復和調試。
內核日志（dmesg）存在一些
warning級別的打印日志，通常與調度（scheduling）、工作隊列（work_queue）有關。分析vmcore文件會發現某個進程的calltrace信息有如下特征：
最近的函數是關于獲取自旋鎖的調用，比如
_raw_spin_lock、queued_spin_lock_slowpath、raw_spin_rq_lock_netsted等。函數調用路徑是從
printk到console_unlock，再到上述獲取自旋鎖的調用。
PID: 99675 TASK: ffff8901818acf80 CPU: 116 COMMAND: "kubelet" #0 [fffffe0001ac9e50] crash_nmi_callback at ffffffff81055acb #1 [fffffe0001ac9e58] nmi_handle at ffffffff81024892 #2 [fffffe0001ac9ea0] default_do_nmi at ffffffff81a358d2 #3 [fffffe0001ac9ec8] exc_nmi at ffffffff81a35adf #4 [fffffe0001ac9ef0] end_repeat_nmi at ffffffff81c013eb [exception RIP: native_queued_spin_lock_slowpath+65] RIP: ffffffff810ff9b1 RSP: ffffc9001da977d8 RFLAGS: 00000002 RAX: 00000000005c0101 RBX: ffff897e7fb00000 RCX: ffff897e7fb38705 RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff897e7fb33600 RBP: ffff8901efa38000 R8: 0000000000000074 R9: ffff897e7fb32f20 R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000 R13: 0000000000000002 R14: ffff8901efa38b44 R15: ffff897e7fb33600 ORIG_RAX: ffffffffffffffff CS: 0010 SS: 0000 --- <NMI exception stack> --- #5 [ffffc9001da977d8] native_queued_spin_lock_slowpath at ffffffff810ff9b1 #6 [ffffc9001da977d8] _raw_spin_lock at ffffffff81a435ea #7 [ffffc9001da977e0] try_to_wake_up at ffffffff810cf3e3 #8 [ffffc9001da97840] __queue_work at ffffffff810b643f #9 [ffffc9001da97888] queue_work_on at ffffffff810b65cc #10 [ffffc9001da97898] soft_cursor at ffffffff815c1b51 #11 [ffffc9001da978f0] bit_cursor at ffffffff815c1718 #12 [ffffc9001da979c0] hide_cursor at ffffffff816591d4 #13 [ffffc9001da979d0] vt_console_print at ffffffff81659fea #14 [ffffc9001da97a38] call_console_drivers.constprop.0 at ffffffff81109a32 #15 [ffffc9001da97a60] console_unlock at ffffffff8110a04d #16 [ffffc9001da97b18] vprintk_emit at ffffffff8110be14 #17 [ffffc9001da97b58] printk at ffffffff819f1053 #18 [ffffc9001da97bb8] show_fault_oops.cold at ffffffff819e9b6b #19 [ffffc9001da97c10] no_context at ffffffff810714bb #20 [ffffc9001da97c48] exc_page_fault at ffffffff81a37628 #21 [ffffc9001da97c70] asm_exc_page_fault at ffffffff81c00ace #22 [ffffc9001da97cf8] __update_load_avg_cfs_rq at ffffffff810f25ee #23 [ffffc9001da97d60] update_load_avg at ffffffff810d8e7a #24 [ffffc9001da97d98] task_tick_fair at ffffffff810daeed #25 [ffffc9001da97dd0] scheduler_tick at ffffffff810ceb9c #26 [ffffc9001da97df8] update_process_times at ffffffff81132d30 #27 [ffffc9001da97e10] tick_sched_handle at ffffffff81144082 #28 [ffffc9001da97e28] tick_sched_timer at ffffffff81144503 #29 [ffffc9001da97e48] __run_hrtimer at ffffffff81133bbc #30 [ffffc9001da97e80] __hrtimer_run_queues at ffffffff81133d6d #31 [ffffc9001da97ec0] hrtimer_interrupt at ffffffff81134250 #32 [ffffc9001da97f20] __sysvec_apic_timer_interrupt at ffffffff81059b51 #33 [ffffc9001da97f38] sysvec_apic_timer_interrupt at ffffffff81a36e01 #34 [ffffc9001da97f50] asm_sysvec_apic_timer_interrupt at ffffffff81c00cc2 RIP: 0000000000429e3a RSP: 00007f2e29ffad48 RFLAGS: 00000202 RAX: 00c00352b0000010 RBX: 00000000075c1048 RCX: 000000c003827800 RDX: 00c00396e8000003 RSI: 0000000000000000 RDI: 0000000000000002 RBP: 00007f2e29ffada0 R8: 7ffffffffffb3a07 R9: 0000000000000000 R10: 000000c000091e98 R11: 0000000000000340 R12: 0000000000000000 R13: 0000000000000e96 R14: 0000000000000000 R15: 0000000000000000 ORIG_RAX: ffffffffffffffff CS: 0033 SS: 002b
問題原因
系統宕機是由Linux社區的printk機制長期存在死鎖的問題導致的，且是已知問題，該問題出現概率較低，但在Alibaba Cloud Linux 3的5.10.134-16.3內核版本出現該問題的概率偏高。
為什么會出現printk死鎖？
內核在持有work_queue（工作隊列）或runqueue（運行隊列，簡稱rq）的自旋鎖后，如果調用printk函數打印內核日志，printk的底層實現會去調用drm驅動程序，而drm驅動程序由于自身的實現原因又會去嘗試對work_queue或rq進行加鎖，導致printk死鎖，最終導致系統宕機。
說明drm驅動嘗試加鎖的詳細信息，請參考drm/fb-helper: Add fb_deferred_io support補丁。
為什么調度（scheduling）和工作隊列（work_queue）會出現
warning日志？由于內核持有work_queue或rq的自旋鎖并使用printk函數打印日志的場景，又通常發生在調度（scheduling）和工作隊列（work_queue）實現代碼的warning路徑上，所以可以觀察到內核的dmesg信息中出現調度（scheduling）和工作隊列（work_queue）相關的報警信息。
為什么Alibaba Cloud Linux 3的
5.10.134-16.3內核版本出現該問題的概率偏高？事實上，調度（scheduling）和工作隊列（work_queue）打印
warning日志的情況并不多，但是在Alibaba Cloud Linux 3的5.10.134-16.3內核版本中，從Linux上游社區回合的異步unthrottle特性存在回歸缺陷，增大了觸發打印warning日志的概率，從而導致Alibaba Cloud Linux 3中出現該問題的概率偏高。
影響范圍
該問題目前是Linux社區共性問題，且觸發該問題的補丁drm/fb-helper: Add fb_deferred_io support是在Linux上游社區的v4.10版本引入。
在Alibaba Cloud Linux的
4.19和5.10內核版本存在該問題。在Alibaba Cloud Linux 3的
5.10.134-16.3內核版本中出現該問題的概率更高。
解決方案
當您發現此類問題時，可以通過以下命令調整printk的打印等級，阻止warning級別的日志打印到串口的方式避開該問題。
如果您的日志系統是依賴捕獲串口輸出而非內核日志（dmesg）信息，請謹慎評估后使用。
該方法會導致串口中的
warning日志缺失，但不會影響內核日志（dmesg）中的warning日志。
sysctl -w kernel.printk="<console_loglevel> <default_message_loglevel> <minimum_console_loglevel> <default_console_loglevel>" >> /etc/sysctl.conf其中kernel.printk的四個值說明如下：
console_loglevel：表示高于（不含）此優先級的信息會被打印至串口。default_message_loglevel：如果在printk時未指定打印等級，則默認使用該等級。minimum_console_loglevel：表示console_loglevel可以被設置的最小值。default_console_loglevel：表示console_loglevel的默認值。
由于Linux將內核的日志打印等級分為8個，等級越低，優先級越高。因此需要阻止warning級別的日志打印到串口，則console_loglevel最大設置為4才合理。命令示例如下：
sysctl -w kernel.printk="4 4 1 7" >> /etc/sysctl.conf日志打印等級說明：
#define LOGLEVEL_EMERG 0 /* system is unusable */
#define LOGLEVEL_ALERT 1 /* action must be taken immediately */
#define LOGLEVEL_CRIT 2 /* critical conditions */
#define LOGLEVEL_ERR 3 /* error conditions */
#define LOGLEVEL_WARNING 4 /* warning conditions */
#define LOGLEVEL_NOTICE 5 /* normal but significant condition */
#define LOGLEVEL_INFO 6 /* informational */
#define LOGLEVEL_DEBUG 7 /* debug-level messages */