蜗窝科技

关于numa loadbance的死锁分析

安庆 · · Linux内核分析 · 阅读 8287 · 2021年5月存档

关于migrate_swap() 和 active_balance()之间的hardlock

背景:这个是在3.10.0-957.el7.x86_64 遇到的一例crash

下面列一下我们是怎么排查并解这个问题的。

一、故障现象

Oppo云智能监控发现机器down机:


KERNEL: /usr/lib/debug/lib/modules/3.10.0-957.el7.x86\_64/vmlinux

....

PANIC: "Kernel panic - not syncing: Hard LOCKUP"

PID: 14

COMMAND: "migration/1"

TASK: ffff8f1bf6bb9040 [THREAD\_INFO: ffff8f1bf6bc4000]

CPU: 1

STATE: TASK\_INTERRUPTIBLE (PANIC)

  

crash> bt

PID: 14 TASK: ffff8f1bf6bb9040 CPU: 1 COMMAND: "migration/1"

#0 [ffff8f4afbe089f0] machine\_kexec at ffffffff83863674

#1 [ffff8f4afbe08a50] \_\_crash\_kexec at ffffffff8391ce12

#2 [ffff8f4afbe08b20] panic at ffffffff83f5b4db

#3 [ffff8f4afbe08ba0] nmi\_panic at ffffffff8389739f

#4 [ffff8f4afbe08bb0] watchdog\_overflow\_callback at ffffffff83949241

#5 [ffff8f4afbe08bc8] \_\_perf\_event\_overflow at ffffffff839a1027

#6 [ffff8f4afbe08c00] perf\_event\_overflow at ffffffff839aa694

#7 [ffff8f4afbe08c10] intel\_pmu\_handle\_irq at ffffffff8380a6b0

#8 [ffff8f4afbe08e38] perf\_event\_nmi\_handler at ffffffff83f6b031

#9 [ffff8f4afbe08e58] nmi\_handle at ffffffff83f6c8fc

#10 [ffff8f4afbe08eb0] do\_nmi at ffffffff83f6cbd8

#11 [ffff8f4afbe08ef0] end\_repeat\_nmi at ffffffff83f6bd69

[exception RIP: native\_queued\_spin\_lock\_slowpath+462]

RIP: ffffffff839121ae RSP: ffff8f1bf6bc7c50 RFLAGS: 00000002

RAX: 0000000000000001 RBX: 0000000000000082 RCX: 0000000000000001

RDX: 0000000000000101 RSI: 0000000000000001 RDI: ffff8f1afdf55fe8---锁

RBP: ffff8f1bf6bc7c50 R8: 0000000000000101 R9: 0000000000000400

R10: 000000000000499e R11: 000000000000499f R12: ffff8f1afdf55fe8

R13: ffff8f1bf5150000 R14: ffff8f1afdf5b488 R15: ffff8f1bf5187818

ORIG\_RAX: ffffffffffffffff CS: 0010 SS: 0018

--- <NMI exception stack> ---

#12 [ffff8f1bf6bc7c50] native\_queued\_spin\_lock\_slowpath at ffffffff839121ae

#13 [ffff8f1bf6bc7c58] queued\_spin\_lock\_slowpath at ffffffff83f5bf4b

#14 [ffff8f1bf6bc7c68] \_raw\_spin\_lock\_irqsave at ffffffff83f6a487

#15 [ffff8f1bf6bc7c80] cpu\_stop\_queue\_work at ffffffff8392fc70

#16 [ffff8f1bf6bc7cb0] stop\_one\_cpu\_nowait at ffffffff83930450

#17 [ffff8f1bf6bc7cc0] load\_balance at ffffffff838e4c6e

#18 [ffff8f1bf6bc7da8] idle\_balance at ffffffff838e5451

#19 [ffff8f1bf6bc7e00] \_\_schedule at ffffffff83f67b14

#20 [ffff8f1bf6bc7e88] schedule at ffffffff83f67bc9

#21 [ffff8f1bf6bc7e98] smpboot\_thread\_fn at ffffffff838ca562

#22 [ffff8f1bf6bc7ec8] kthread at ffffffff838c1c31

#23 [ffff8f1bf6bc7f50] ret\_from\_fork\_nospec\_begin at ffffffff83f74c1d

crash>

二、故障现象分析

hardlock一般是由于关中断时间过长,从堆栈看,上面的"migration/1" 进程在抢spinlock,

由于_raw_spin_lock_irqsave 会先调用 arch_local_irq_disable,然后再去拿锁,而

arch_local_irq_disable 是常见的关中断函数,下面分析这个进程想要拿的锁被谁拿着。


x86架构下,native\_queued\_spin\_lock\_slowpath的rdi就是存放锁地址的

  

crash> arch\_spinlock\_t ffff8f1afdf55fe8

struct arch\_spinlock\_t {

val = {

counter = 257

}

}

下面,我们需要了解,这个是一把什么锁。

从调用链分析 idle_balance–>load_balance–>stop_one_cpu_nowait–>cpu_stop_queue_work

反汇编 cpu_stop_queue_work 拿锁阻塞的代码:


crash> dis -l ffffffff8392fc70

/usr/src/debug/kernel-3.10.0-957.el7/linux-3.10.0-957.el7.x86\_64/kernel/stop\_machine.c: 91

0xffffffff8392fc70 <cpu\_stop\_queue\_work+48>: cmpb $0x0,0xc(%rbx)

  

85 static void cpu\_stop\_queue\_work(unsigned int cpu, struct cpu\_stop\_work \*work)

86 {

87 struct cpu\_stopper \*stopper = &per\_cpu(cpu\_stopper, cpu);

88 unsigned long flags;

89

90 spin\_lock\_irqsave(&stopper->lock, flags);---所以是卡在拿这把锁

91 if (stopper->enabled)

92 \_\_cpu\_stop\_queue\_work(stopper, work);

93 else

94 cpu\_stop\_signal\_done(work->done, false);

95 spin\_unlock\_irqrestore(&stopper->lock, flags);

96 }

看起来 需要根据cpu号,来获取对应的percpu变量 cpu_stopper,这个入参在 load_balance 函数中找到的

最忙的rq,然后获取其对应的cpu号:


6545 static int load\_balance(int this\_cpu, struct rq \*this\_rq,

6546 struct sched\_domain \*sd, enum cpu\_idle\_type idle,

6547 int \*should\_balance)

6548 {

....

6735 if (active\_balance) {

6736 stop\_one\_cpu\_nowait(cpu\_of(busiest),

6737 active\_load\_balance\_cpu\_stop, busiest,

6738 &busiest->active\_balance\_work);

6739 }

....

6781 }

  

crash> dis -l load\_balance |grep stop\_one\_cpu\_nowait -B 6

0xffffffff838e4c4d <load\_balance+2045>: callq 0xffffffff83f6a0e0 <\_raw\_spin\_unlock\_irqrestore>

/usr/src/debug/kernel-3.10.0-957.el7/linux-3.10.0-957.el7.x86\_64/kernel/sched/fair.c: 6736

0xffffffff838e4c52 <load\_balance+2050>: mov 0x930(%rbx),%edi------------根据rbx可以取cpu号,rbx就是最忙的rq

0xffffffff838e4c58 <load\_balance+2056>: lea 0x908(%rbx),%rcx

0xffffffff838e4c5f <load\_balance+2063>: mov %rbx,%rdx

0xffffffff838e4c62 <load\_balance+2066>: mov $0xffffffff838de690,%rsi

0xffffffff838e4c69 <load\_balance+2073>: callq 0xffffffff83930420 <stop\_one\_cpu\_nowait>

然后我们再栈中取的数据如下:


最忙的组是:

crash> rq.cpu ffff8f1afdf5ab80

cpu = 26

也就是说,1号cpu在等 percpu变量cpu_stopper 的26号cpu的锁。

然后我们搜索这把锁在其他哪个进程的栈中,找到了如下:


ffff8f4957fbfab0: ffff8f1afdf55fe8 --------这个在 355608 的栈中

crash> kmem ffff8f4957fbfab0

PID: 355608

COMMAND: "custom\_exporter"

TASK: ffff8f4aea3a8000 [THREAD\_INFO: ffff8f4957fbc000]

CPU: 26--------刚好也是运行在26号cpu的进程

STATE: TASK\_RUNNING (ACTIVE)

下面,就需要分析,为什么位于26号cpu的进程 custom_exporter 会长时间拿着 ffff8f1afdf55fe8

我们来分析26号cpu的堆栈:


crash> bt -f 355608

PID: 355608 TASK: ffff8f4aea3a8000 CPU: 26 COMMAND: "custom\_exporter"

.....

#3 [ffff8f1afdf48ef0] end\_repeat\_nmi at ffffffff83f6bd69

[exception RIP: try\_to\_wake\_up+114]

RIP: ffffffff838d63d2 RSP: ffff8f4957fbfa30 RFLAGS: 00000002

RAX: 0000000000000001 RBX: ffff8f1bf6bb9844 RCX: 0000000000000000

RDX: 0000000000000001 RSI: 0000000000000003 RDI: ffff8f1bf6bb9844

RBP: ffff8f4957fbfa70 R8: ffff8f4afbe15ff0 R9: 0000000000000000

R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000

R13: ffff8f1bf6bb9040 R14: 0000000000000000 R15: 0000000000000003

ORIG\_RAX: ffffffffffffffff CS: 0010 SS: 0000

--- <NMI exception stack> ---

#4 [ffff8f4957fbfa30] try\_to\_wake\_up at ffffffff838d63d2

ffff8f4957fbfa38: 000000000001ab80 0000000000000086

ffff8f4957fbfa48: ffff8f4afbe15fe0 ffff8f4957fbfb48

ffff8f4957fbfa58: 0000000000000001 ffff8f4afbe15fe0

ffff8f4957fbfa68: ffff8f1afdf55fe0 ffff8f4957fbfa80

ffff8f4957fbfa78: ffffffff838d6705

#5 [ffff8f4957fbfa78] wake\_up\_process at ffffffff838d6705

ffff8f4957fbfa80: ffff8f4957fbfa98 ffffffff8392fc05

#6 [ffff8f4957fbfa88] \_\_cpu\_stop\_queue\_work at ffffffff8392fc05

ffff8f4957fbfa90: 000000000000001a ffff8f4957fbfbb0

ffff8f4957fbfaa0: ffffffff8393037a

#7 [ffff8f4957fbfaa0] stop\_two\_cpus at ffffffff8393037a

.....

ffff8f4957fbfbb8: ffffffff838d3867

#8 [ffff8f4957fbfbb8] migrate\_swap at ffffffff838d3867

ffff8f4957fbfbc0: ffff8f4aea3a8000 ffff8f1ae77dc100 -------栈中的 migration\_swap\_arg

ffff8f4957fbfbd0: 000000010000001a 0000000080490f7c

ffff8f4957fbfbe0: ffff8f4aea3a8000 ffff8f4957fbfc30

ffff8f4957fbfbf0: 0000000000000076 0000000000000076

ffff8f4957fbfc00: 0000000000000371 ffff8f4957fbfce8

ffff8f4957fbfc10: ffffffff838dd0ba

#9 [ffff8f4957fbfc10] task\_numa\_migrate at ffffffff838dd0ba

ffff8f4957fbfc18: ffff8f1afc121f40 000000000000001a

ffff8f4957fbfc28: 0000000000000371 ffff8f4aea3a8000 ---这里ffff8f4957fbfc30 就是 task\_numa\_env 的存放在栈中的地址

ffff8f4957fbfc38: 000000000000001a 000000010000003f

ffff8f4957fbfc48: 000000000000000b 000000000000022c

ffff8f4957fbfc58: 00000000000049a0 0000000000000012

ffff8f4957fbfc68: 0000000000000001 0000000000000003

ffff8f4957fbfc78: 000000000000006f 000000000000499f

ffff8f4957fbfc88: 0000000000000012 0000000000000001

ffff8f4957fbfc98: 0000000000000070 ffff8f1ae77dc100

ffff8f4957fbfca8: 00000000000002fb 0000000000000001

ffff8f4957fbfcb8: 0000000080490f7c ffff8f4aea3a8000 ---rbx压栈在此,所以这个就是current

ffff8f4957fbfcc8: 0000000000017a48 0000000000001818

ffff8f4957fbfcd8: 0000000000000018 ffff8f4957fbfe20

ffff8f4957fbfce8: ffff8f4957fbfcf8 ffffffff838dd4d3

#10 [ffff8f4957fbfcf0] numa\_migrate\_preferred at ffffffff838dd4d3

ffff8f4957fbfcf8: ffff8f4957fbfd88 ffffffff838df5b0

.....

crash>

crash>

整体上看,26号上的cpu也正在进行numa的balance动作,简单展开介绍一下numa在balance下的动作

在 task_tick_fair 函数中:


static void task\_tick\_fair(struct rq \*rq, struct task\_struct \*curr, int queued)

{

struct cfs\_rq \*cfs\_rq;

struct sched\_entity \*se = &curr->se;

  

for\_each\_sched\_entity(se) {

cfs\_rq = cfs\_rq\_of(se);

entity\_tick(cfs\_rq, se, queued);

}

  

if (numabalancing\_enabled)----------如果开启numabalancing,则会调用task\_tick\_numa

task\_tick\_numa(rq, curr);

  

update\_rq\_runnable\_avg(rq, 1);

}

而 task_tick_numa 会根据扫描情况,将当前进程需要numa_balance的时候推送到一个work中。

通过调用change_prot_numa将所有映射到VMA的PTE页表项该为PAGE_NONE,使得下次进程访问页表的时候

产生缺页中断,handle_pte_fault 函数 会由于缺页中断的机会来根据numa 选择更好的node,具体不再展开。

在 26号cpu的调用链中,stop_two_cpus–>cpu_stop_queue_two_works–>__cpu_stop_queue_work 函数

由于 cpu_stop_queue_two_works 被内联了,但是 cpu_stop_queue_two_works 调用 __cpu_stop_queue_work

有两次,所以需要根据压栈地址判断当前是哪次调用出现问题。


227 static int cpu\_stop\_queue\_two\_works(int cpu1, struct cpu\_stop\_work \*work1,

228 int cpu2, struct cpu\_stop\_work \*work2)

229 {

230 struct cpu\_stopper \*stopper1 = per\_cpu\_ptr(&cpu\_stopper, cpu1);

231 struct cpu\_stopper \*stopper2 = per\_cpu\_ptr(&cpu\_stopper, cpu2);

232 int err;

233

234 lg\_double\_lock(&stop\_cpus\_lock, cpu1, cpu2);

235 spin\_lock\_irq(&stopper1->lock);---注意到这里已经持有了stopper1的锁

236 spin\_lock\_nested(&stopper2->lock, SINGLE\_DEPTH\_NESTING);

.....

243 \_\_cpu\_stop\_queue\_work(stopper1, work1);

244 \_\_cpu\_stop\_queue\_work(stopper2, work2);

.....

251 }

  

根据压栈的地址:


#5 [ffff8f4957fbfa78] wake\_up\_process at ffffffff838d6705

ffff8f4957fbfa80: ffff8f4957fbfa98 ffffffff8392fc05

#6 [ffff8f4957fbfa88] \_\_cpu\_stop\_queue\_work at ffffffff8392fc05

ffff8f4957fbfa90: 000000000000001a ffff8f4957fbfbb0

ffff8f4957fbfaa0: ffffffff8393037a

#7 [ffff8f4957fbfaa0] stop\_two\_cpus at ffffffff8393037a

ffff8f4957fbfaa8: 0000000100000001 ffff8f1afdf55fe8

  

crash> dis -l ffffffff8393037a 2

/usr/src/debug/kernel-3.10.0-957.el7/linux-3.10.0-957.el7.x86\_64/kernel/stop\_machine.c: 244

0xffffffff8393037a <stop\_two\_cpus+394>: lea 0x48(%rsp),%rsi

0xffffffff8393037f <stop\_two\_cpus+399>: mov %r15,%rdi

说明压栈的是244行的地址,也就是说目前调用的是243行的 __cpu_stop_queue_work。

然后分析对应的入参:


crash> task\_numa\_env ffff8f4957fbfc30

struct task\_numa\_env {

p = 0xffff8f4aea3a8000,

src\_cpu = 26,

src\_nid = 0,

dst\_cpu = 63,

dst\_nid = 1,

src\_stats = {

nr\_running = 11,

load = 556, ---load高

compute\_capacity = 18848, ---容量相当

task\_capacity = 18,

has\_free\_capacity = 1

},

dst\_stats = {

nr\_running = 3,

load = 111, ---load低,且容量相当,要迁移过来

compute\_capacity = 18847, ---容量相当

task\_capacity = 18,

has\_free\_capacity = 1

},

imbalance\_pct = 112,

idx = 0,

best\_task = 0xffff8f1ae77dc100, ---要对调的task,是通过 task\_numa\_find\_cpu-->task\_numa\_compare-->task\_numa\_assign 来获取的

best\_imp = 763,

best\_cpu = 1---最佳的swap的对象对于1号cpu

}

  

crash> migration\_swap\_arg ffff8f4957fbfbc0

struct migration\_swap\_arg {

src\_task = 0xffff8f4aea3a8000,

dst\_task = 0xffff8f1ae77dc100,

src\_cpu = 26,

dst\_cpu = 1-----选择的dst cpu为1

}

根据 cpu_stop_queue_two_works 的代码,它在持有 cpu_stopper:26号cpu锁的情况下,去

调用try_to_wake_up ,wake的对象是 用来migrate的 kworker。


static void \_\_cpu\_stop\_queue\_work(struct cpu\_stopper \*stopper,

struct cpu\_stop\_work \*work)

{

list\_add\_tail(&work->list, &stopper->works);

wake\_up\_process(stopper->thread);//其实一般就是唤醒 migration

}

由于最佳的cpu对象为1,所以需要cpu上的migrate来拉取进程。


crash> p cpu\_stopper:1

per\_cpu(cpu\_stopper, 1) = $33 = {

thread = 0xffff8f1bf6bb9040, ----需要唤醒的目的task

lock = {

{

rlock = {

raw\_lock = {

val = {

counter = 1

}

}

}

}

},

enabled = true,

works = {

next = 0xffff8f4957fbfac0,

prev = 0xffff8f4957fbfac0

},

stop\_work = {

list = {

next = 0xffff8f4afbe16000,

prev = 0xffff8f4afbe16000

},

fn = 0xffffffff83952100,

arg = 0x0,

done = 0xffff8f1ae3647c08

}

}

crash> kmem 0xffff8f1bf6bb9040

CACHE NAME OBJSIZE ALLOCATED TOTAL SLABS SSIZE

ffff8eecffc05f00 task\_struct 4152 1604 2219 317 32k

SLAB MEMORY NODE TOTAL ALLOCATED FREE

fffff26501daee00 ffff8f1bf6bb8000 1 7 7 0

FREE / [ALLOCATED]

[ffff8f1bf6bb9040]

  

PID: 14

COMMAND: "migration/1"--------------目的task就是对应的cpu上的migration

TASK: ffff8f1bf6bb9040 [THREAD\_INFO: ffff8f1bf6bc4000]

CPU: 1

STATE: TASK\_INTERRUPTIBLE (PANIC)

  

PAGE PHYSICAL MAPPING INDEX CNT FLAGS

fffff26501daee40 3076bb9000 0 0 0 6fffff00008000 tail

  

现在的问题是,虽然我们知道了当前cpu26号进程在拿了锁的情况下去唤醒1号cpu上的migrate进程,

那么为什么会迟迟不释放锁,导致1号cpu因为等待该锁时间过长而触发了hardlock的panic呢?

下面就分析,为什么它持锁的时间这么长:


#3 [ffff8f1afdf48ef0] end\_repeat\_nmi at ffffffff83f6bd69

[exception RIP: try\_to\_wake\_up+114]

RIP: ffffffff838d63d2 RSP: ffff8f4957fbfa30 RFLAGS: 00000002

RAX: 0000000000000001 RBX: ffff8f1bf6bb9844 RCX: 0000000000000000

RDX: 0000000000000001 RSI: 0000000000000003 RDI: ffff8f1bf6bb9844

RBP: ffff8f4957fbfa70 R8: ffff8f4afbe15ff0 R9: 0000000000000000

R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000

R13: ffff8f1bf6bb9040 R14: 0000000000000000 R15: 0000000000000003

ORIG\_RAX: ffffffffffffffff CS: 0010 SS: 0000

--- <NMI exception stack> ---

#4 [ffff8f4957fbfa30] try\_to\_wake\_up at ffffffff838d63d2

ffff8f4957fbfa38: 000000000001ab80 0000000000000086

ffff8f4957fbfa48: ffff8f4afbe15fe0 ffff8f4957fbfb48

ffff8f4957fbfa58: 0000000000000001 ffff8f4afbe15fe0

ffff8f4957fbfa68: ffff8f1afdf55fe0 ffff8f4957fbfa80

  

crash> dis -l ffffffff838d63d2

/usr/src/debug/kernel-3.10.0-957.el7/linux-3.10.0-957.el7.x86\_64/kernel/sched/core.c: 1790

0xffffffff838d63d2 <try\_to\_wake\_up+114>: mov 0x28(%r13),%eax

  

1721 static int

1722 try\_to\_wake\_up(struct task\_struct \*p, unsigned int state, int wake\_flags)

1723 {

.....

1787 \* If the owning (remote) cpu is still in the middle of schedule() with

1788 \* this task as prev, wait until its done referencing the task.

1789 \*/

1790 while (p->on\_cpu)---------原来循环在此

1791 cpu\_relax();

.....

1814 return success;

1815 }

我们用一个简单的图来表示一下这个hardlock:


CPU1 CPU26

schedule(.prev=migrate/1) <fault>

pick\_next\_task() ...

idle\_balance() migrate\_swap()

active\_balance() stop\_two\_cpus()

spin\_lock(stopper0->lock)

spin\_lock(stopper1->lock)

try\_to\_wake\_up

pause() -- waits for schedule()

stop\_one\_cpu(1)

spin\_lock(stopper26->lock) -- waits for stopper lock

查看上游的补丁,


static void \_\_cpu\_stop\_queue\_work(struct cpu\_stopper \*stopper,

- struct cpu\_stop\_work \*work)

+ struct cpu\_stop\_work \*work,

+ struct wake\_q\_head \*wakeq)

{

list\_add\_tail(&work->list, &stopper->works);

- wake\_up\_process(stopper->thread);

+ wake\_q\_add(wakeq, stopper->thread);

}

三、故障复现

1.由于这个是一个race condition导致的hardlock,逻辑上分析已经没有问题了,就没有花时间去复现,

该环境运行一个dpdk的node,不过为了性能设置了只在一个numa节点上运行,可以频繁造成numa的不均衡,所以要复现的同学,

可以参考单numa节点上运行dpdk来复现,会概率大一些。

四、故障规避或解决

我们的解决方案是:

1.关闭numa的自动balance.

2.手工合入 linux社区的 0b26351b910f 补丁

3.这个补丁在centos的 3.10.0-974.el7 合入了:

[kernel] stop_machine, sched: Fix migrate_swap() vs. active_balance() deadlock (Phil Auld) [1557061]

同时红帽又反向合入到了3.10.0-957.27.2.el7.x86_64,所以把centos内核升级到 3.10.0-957.27.2.el7.x86_64也是

一种选择。

继续讨论

新讨论请用 GitHub 账号在下方发言——评论会保存在本仓库的 Discussions 里,与站点同寿; 再下方的「历史评论」是原站的只读存档。

评论(3 条,只读存档)

以下为原站的历史评论(只读存档);继续讨论请用上方的评论区。

  • nswcfd@cu

    感谢分享这些经典案例!
  • y

    精彩的分析,希望有更多用例分享。
  • Kiddy

    这个问题在内核5.15也存在,但是我看好像合入了这个patch。博主能给点思路吗