Re: [PATCH] psi:fix divide by zero in psi_update_stats

From: Peter Zijlstra
Date: Fri Nov 08 2019 - 05:05:17 EST



https://people.kernel.org/tglx/notes-about-netiquette-qw89

On Fri, Nov 08, 2019 at 05:49:01PM +0800, Jingfeng Xie wrote:
> It happens multiple times on our online machines, the crash call trace is like below:
> [58914.066423] divide error: 0000 [#1] SMP
> [58914.070416] Modules linked in: ipmi_poweroff ipmi_watchdog toa overlay fuse tcp_diag inet_diag binfmt_misc aisqos(O) aisqos_hotfixes(O)
> [58914.083158] CPU: 94 PID: 140364 Comm: kworker/94:2 Tainted: G W OE K 4.9.151-015.ali3000.alios7.x86_64 #1
> [58914.093722] Hardware name: Alibaba Alibaba Cloud ECS/Alibaba Cloud ECS, BIOS 3.23.34 02/14/2019
> [58914.102728] Workqueue: events psi_update_work
> [58914.107258] task: ffff8879da83c280 task.stack: ffffc90059dcc000
> [58914.113336] RIP: 0010:[] [] psi_update_stats+0x1c1/0x330
> [58914.122183] RSP: 0018:ffffc90059dcfd60 EFLAGS: 00010246
> [58914.127650] RAX: 0000000000000000 RBX: ffff8858fe98be50 RCX: 000000007744d640
> [58914.134947] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 00003594f700648e
> [58914.142243] RBP: ffffc90059dcfdf8 R08: 0000359500000000 R09: 0000000000000000
> [58914.149538] R10: 0000000000000000 R11: 0000000000000000 R12: 0000359500000000
> [58914.156837] R13: 0000000000000000 R14: 0000000000000000 R15: ffff8858fe98bd78
> [58914.164136] FS: 0000000000000000(0000) GS:ffff887f7f380000(0000) knlGS:0000000000000000
> [58914.172529] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [58914.178467] CR2: 00007f2240452090 CR3: 0000005d5d258000 CR4: 00000000007606f0
> [58914.185765] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [58914.193061] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> [58914.200360] PKRU: 55555554
> [58914.203221] Stack:
> [58914.205383] ffff8858fe98bd48 00000000000002f0 0000002e81036d09 ffffc90059dcfde8
> [58914.213168] ffff8858fe98bec8 0000000000000000 0000000000000000 0000000000000000
> [58914.220951] 0000000000000000 0000000000000000 0000000000000000 0000000000000000
> [58914.228734] Call Trace:
> [58914.231337] [] psi_update_work+0x22/0x60
> [58914.237067] [] process_one_work+0x189/0x420
> [58914.243063] [] worker_thread+0x4e/0x4b0
> [58914.248701] [] ? process_one_work+0x420/0x420
> [58914.254869] [] kthread+0xe6/0x100
> [58914.259994] [] ? kthread_park+0x60/0x60
> [58914.265640] [] ret_from_fork+0x39/0x50
> [58914.271193] Code: 41 29 c3 4d 39 dc 4d 0f 42 dc <49> f7 f1 48 8b 13 48 89 c7 48 c1
> [58914.279691] RIP [] psi_update_stats+0x1c1/0x330
> [58914.286053] RSP
>
> With full kdump vmcore analysis, The R8 is period in psi_update_stats which results in the zero division error.

This does not answer either question I asked.

> How can this happen? Is that a valid case or should we be avoiding that?

This does not explain how the period got so large, nor if that is a
valid/expected scenario.