zoukankan      html  css  js  c++  java
  • 嵌套OOPS导致系统卡死 每个CPU都上报softlockup的问题

    问题现象:在ARM服务器上,构造oops异常,本应该产生panic,进入dump流程,并且系统重启,但是系统并未重启,而是出现了卡死,在串口会隔一段时间就循环打印调用栈信息。如下所示

    linux-fATqUY login: [ME] Fault detect start!
    [ME] Fault detect start!
    [ 254.202183] Unable to handle kernel NULL pointer dereference at virtual address 0000000000000000
    [ 254.211111] Mem abort info:
    [ 254.213939] ESR = 0x96000044
    [ 254.217042] Exception class = DABT (current EL), IL = 32 bits
    [ 254.223054] SET = 0, FnV = 0
    [ 254.226154] EA = 0, S1PTW = 0
    [ 254.229335] Data abort info:
    [ 254.232261] ISV = 0, ISS = 0x00000044
    [ 254.236155] CM = 0, WnR = 1
    [ 254.239167] user pgtable: 4k pages, 48-bit VAs, pgdp = 00000000509fb5ee
    [ 254.245883] [0000000000000000] pgd=0000000000000000
    [ 254.250838] Internal error: Oops: 96000044 [#1] SMP
    [ 254.255785] CPU: 0 PID: 58147 Comm: gen_seri_oops/0 Kdump: loaded Tainted: 
    [ 254.273985] pstate: 60000005 (nZCv daif -PAN -UAO)
    [ 254.278851] pc : gen_seri_oops+0x28/0x38 [kpgen_kbox]
    [ 254.283971] lr : gen_seri_oops+0x1c/0x38 [kpgen_kbox]
    [ 254.289089] sp : ffff000033ea3e50
    [ 254.292443] x29: ffff000033ea3e50 x28: 0000000000000000
    [ 254.297831] x27: ffff000035fdbb08 x26: ffff803f713412b8
    [ 254.303218] x25: ffff000000fb2370 x24: 0000000000000000
    [ 254.308605] x23: ffff0000091bcb10 x22: ffff80df64dc2e80
    [ 254.380350] Process gen_seri_oops/0 (pid: 58147, stack limit = 0x0000000088aed8c0)
    [ 254.391639] Call trace:
    [ 254.397760] gen_seri_oops+0x28/0x38 [kpgen_kbox]
    [ 254.406069] kthread+0x108/0x138
    [ 254.412721] ret_from_fork+0x10/0x18
    [ 254.419733] Code: 95c66ac7 d2800001 52800c22 52800000 (39000022)
    [ 254.429390] die event detected
    [ 254.436533] Unable to handle kernel NULL pointer dereference at virtual address 0000000000000008
    [ 254.448966] Mem abort info:
    [ 254.455502] ESR = 0x96000004
    [ 254.462278] Exception class = DABT (current EL), IL = 32 bits
    [ 254.472023] SET = 0, FnV = 0
    [ 254.478845] EA = 0, S1PTW = 0
    [ 254.485645] Data abort info:
    [ 254.492130] ISV = 0, ISS = 0x00000004
    [ 254.499576] CM = 0, WnR = 0
    [ 254.505933] user pgtable: 4k pages, 48-bit VAs, pgdp = 00000000509fb5ee
    [ 254.515960] [0000000000000008] pgd=0000000000000000

      360.462046] watchdog: BUG: soft lockup - CPU#35 stuck for 22s! [docker-containe:29506]
    [  360.473208] Modules linked in: pt_MASQUERADE(E) iptable_nat(E) ……
    [  360.565132] CPU: 35 PID: 29506 Comm: docker-containe Kdump: loaded Tainted: G           OEL    4.19.5-1.1.29.aarch64 #1[  360.595535] pstate: 80000005 (Nzcv daif -PAN -UAO)
    [  360.604905] pc : smp_call_function_many+0x308/0x370
    [  360.614105] lr : smp_call_function_many+0x2c4/0x370
    [  360.623278] sp : ffff00002f4739e0
    [  360.630878] x29: ffff00002f4739e0 x28: ffff000009592184 
    [  360.640673] x27: ffff80bffbeb2f08 x26: 0000000000000000 
    [  360.650447] x25: ffff00000818a790 x24: 0000000000000001 
    [  360.660310] x23: 0000000000001000 x22: ffff000009592184 
    [  360.670118] x21: ffff000009589000 x20: ffff80bffbeb2d08 
    [  360.680004] x19: ffff80bffbeb2d00 x18: 000000000bf5d62e 
    [  360.689922] x17: 000000bf5d62e000 x16: 000000bf5d62f000 
    [  360.699700] x15: 0000000000000008 x14: 0000000000000000 
    [  360.709468] x13: 0000000000000001 x12: ffff803f72c8b530 
    [  360.719251] x11: 0000000000000000 x10: 0000000000000b80 
    [  360.728983] x9 : 0000000000000000 x8 : ffff80bffbeb3108 
    [  360.738859] x7 : 0000000000000000 x6 : 000000000000003f 
    [  360.748533] x5 : 0000000000000000 x4 : fffffff7ffffffff 
    [  360.758230] x3 : 0000000000000000 x2 : ffff803ffbe69638 
    [  360.767909] x1 : 0000000000000003 x0 : 0000000000000000 
    [  360.777504] Call trace:
    [  360.784282]  smp_call_function_many+0x308/0x370
    [  360.793075]  kick_all_cpus_sync+0x30/0x38
    [  360.801443]  sync_icache_aliases+0x74/0x98
    [  360.809852]  __sync_icache_dcache+0x94/0xc8
    [  360.818371]  alloc_set_pte+0x460/0x570
    [  360.826435]  filemap_map_pages+0x3e0/0x400
    [  360.834510]  __handle_mm_fault+0xb78/0x10f0
    [  360.842743]  handle_mm_fault+0xf4/0x1c0
    [  360.850561]  do_page_fault+0x230/0x488
    [  360.858095]  do_translation_fault+0x74/0x84
    [  360.865948]  do_mem_abort+0x6c/0x130
    [  360.873255]  do_el0_ia_bp_hardening+0x64/0xa8
    [  360.881020]  el0_ia+0x18/0x1c
    [  364.514043] watchdog: BUG: soft lockup - CPU#51 stuck for 22s! [vm_io_monitor.p:10065]
    下面的内容同上
    [ 464.446045] watchdog: BUG: soft lockup - CPU#30 stuck for 22s! [kill:2031]
    [  516.538048] watchdog: BUG: soft lockup - CPU#58 stuck for 23s! [libvirtd:29334]
    [  576.358044] watchdog: BUG: soft lockup - CPU#2 stuck for 22s! [logrotate:2045]

    问题原因:在进入dump流程中,dump相关的组件如kernel box出现了空指针访问,出现了oops嵌套。每次在出现oops后,进入内核异常处理流程,执行die函数,该函数中会获取锁,raw_spin_lock_irqsave($die_lock,flags),然后又会在通知链中调用kernel box的注册回调函数,在回调过程中,由于这个回调函数内部又存在空指针访问,又出现oops,又走入了异常处理流程,进入die函数,那么这是想要获取锁,就获取不到,一直在等锁。

    问题来了:

    1、为何每个cpu打印调用栈都是stuck 20s左右呢?

    2、如果一个cpu出现了死锁,其他cpu为何会softlockup呢?

    3、为啥每个cpu的调用栈都在smp_call_function_many

           现在我们来看第一个问题,20s的时间刚好是softlockup的时间,那么什么是softlockup呢,其实说白了,就是抢占被长时间关闭,导致进程无法调度。系统为每个cpu core注册了一个一般的kernel线程,这个线程会定期的调用watchdog函数,这个函数在时钟中断更新时,kernel线程才会被得到运行。当kernel线程里的watchdog函数中的一个watchdog_touch_ts变量在最近20s没有被更新,那就意味这个这个线程在20s内没有被调度,很有可能就是在某个cpu core上抢占被关闭了。所以调度器没法进行调度。那么与之对应的就是hardlockup,是中断被长时间关闭导致的更严重的问题。

           那么,为什么一个cpu上出现了死锁,其他的cpu也会出现softlockup呢,让我们来分析一下softlockup的调用栈,在不清楚这些calltrace函数都是干什么的时候,分析为啥其他cpu上也会出现softlockup是一件难事。经过我多次搜索,差不多理清了思路。调用栈中的两个关键函数是kick_all_cpus_sync, sync_icache_aliases,从函数名称大概能看出这些函数是用来做cpu之间的cache同步的。我们服务器上大概有64个cpu,为了保证cache的一致性,应该会有一种机制来对所有cpu进行同步 。那么如何进行同步,从一篇patch文章中搜到https://patchwork.kernel.org/patch/10325093/,可以查到一些相关信息,如下内容:

    kick_all_cpus_sync() forces all CPUs to sync caches by sending broadcast
    IPI.  If CPU is in extended quiescent state (idle task or nohz_full
    userspace), this work may be done at the exit of this state.

    也就是说通过广播IPI中断,来强制让所有cpu来同步cache。具体的IPI中断的相关介绍可以参考http://www.voidcn.com/article/p-auwhbhgz-oh.html。IPI中断,是核间通信同步的一种方式。

        这篇博客https://segmentfault.com/a/1190000017238912,其实与我遇到的问题很像,摘录这里的一段总结:

    一方面,为了避免产生竞争,线程在刷新本地tlb的时候,会停掉抢占。这就导致一个结果:其他的线程,当然包括watchdog线程,没有办法被调度执行(soft lockup)。另外一方面,为了要求其他cpu同步地刷新tlb,当前线程会使用ipi和其他cpu同步进展,直到其他cpu也完成刷新为止。其他cpu如果迟迟不配合,那么当前线程就会死等。

        我们来看一下   smp_call_function_many这个函数的最后面就是在等待。

    void smp_call_function_many(const struct cpumask *mask,
                    smp_call_func_t func, void *info, bool wait)
    {
    ……
        if (wait) {
            for_each_cpu(cpu, cfd->cpumask) {
                struct call_single_data *csd;
    
                csd = per_cpu_ptr(cfd->csd, cpu);
                csd_lock_wait(csd);
            }
         }
    }

            那么当cpu 0上出现了oops后,后面又出现了死锁,在刚进入oops时,做的第一件事情就是禁用中断。这个非常好理解,oops逻辑要做的事情是保存现场,它当然不希望,中断在这个时候破坏问题现场。

            分析到这里,这个问题就清晰了,当其他cpu例行公事的发过来IPI中断,CPU0 出现了死锁无法响应,于是其他cpu就在死等,进而导致其他cpu上都产生了softlockup。

    附录:

    do_mem_abort是在arm体系架构中,当出现缺页异常,或者访问空指针后arm的中断异常处理。__handle_mm_fault这个函数是在处理大页缺页时的处理函数。具体可以参考http://www.leviathan.vip/2019/03/03/Linux%E5%86%85%E6%A0%B8%E6%BA%90%E7%A0%81%E5%88%86%E6%9E%90-%E5%86%85%E5%AD%98%E8%AF%B7%E9%A1%B5%E6%9C%BA%E5%88%B6/

    内核访问空指针之后的处理流程 https://blog.csdn.net/rikeyone/article/details/80021720https://blog.csdn.net/zangdongming/article/details/38543059

  • 相关阅读:
    Android入门:监听ContentProvider数据改变
    Android入门:ListView(SimpleCursorAdapter实现)
    Android入门:ContentProvider
    Android入门:ListView(继承BaseAdapter实现)
    随机生成字符串实现
    很惊讶douban.com是用python语言的一个框架写的
    简单的总是好的,在这个复杂的世界: java simple log
    Quixtoe比PHP更简单吗?
    python 与 ruby (ruby学习资源大全)
    Web的未来:语义网
  • 原文地址:https://www.cnblogs.com/xingmuxin/p/11317794.html
Copyright © 2011-2022 走看看