Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1757806AbcCCV5S (ORCPT ); Thu, 3 Mar 2016 16:57:18 -0500 Received: from mail.kernel.org ([198.145.29.136]:39130 "EHLO mail.kernel.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751334AbcCCV5Q (ORCPT ); Thu, 3 Mar 2016 16:57:16 -0500 Date: Thu, 3 Mar 2016 13:57:12 -0800 From: Jaegeuk Kim To: sasha.levin@oracle.com Cc: Chris Mason , linux-kernel@vger.kernel.org, stable@vger.kernel.org Subject: Soft lockups in v3.18.27 Message-ID: <20160303215712.GA15737@jaegeuk.hsd1.ca.comcast.net> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline User-Agent: Mutt/1.5.23 (2014-03-12) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 4314 Lines: 67 Hi Sasha, When I test v3.18.27 in the stable line, I'm suffering from the following soft lockups. This occurs during xfstests/013, which is 100% reproducile. I've confirmed that the latest kernel has no problem. [26459.346781] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 23s! [kworker/u2:3:50] [26458.347037] Modules linked in: seqiv cts f2fs binfmt_misc ppdev crc32_pclmul aesni_intel aes_x86_64 lrw gf128mul glue_helper ablk_helper cryptd serio_raw joydev snd_intel8x0 snd_ac97_codec ac97_bus snd_pcm i2c_piix4 snd_timer snd soundcore parport_pc parport autofs4 hid_generic usbhid hid psmouse ahci libahci e1000 pata_acpi video [26458.347060] irq event stamp: 1126550 [26458.347061] hardirqs last enabled at (1126549): [] restore_args+0x0/0x30 [26458.347076] hardirqs last disabled at (1126550): [] apic_timer_interrupt+0x6d/0x80 [26458.347078] softirqs last enabled at (1126546): [] __do_softirq+0x3af/0x640 [26458.347082] softirqs last disabled at (1126541): [] irq_exit+0xd5/0xe0 [26458.347087] CPU: 0 PID: 50 Comm: kworker/u2:3 Tainted: G L 3.18.27+ #5 [26458.347089] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006 [26458.347093] Workqueue: writeback bdi_writeback_workfn (flush-8:16) [26458.347096] task: ffff880077bc4340 ti: ffff880036174000 task.ti: ffff880036174000 [26458.347098] RIP: 0010:[] [] lock_acquire+0xf7/0x2d0 [26458.347102] RSP: 0018:ffff880036177a98 EFLAGS: 00000292 [26458.347103] RAX: ffff880077bc4340 RBX: 0000000000000296 RCX: 0000000000000005 [26458.347104] RDX: ffff880077bc4c00 RSI: 0000000000000000 RDI: 0000000000000292 [26458.347105] RBP: ffff880036177b08 R08: 0000000000070bf0 R09: 3f31fa110447c000 [26458.347106] R10: ffff880077bc4b60 R11: 0000000000000004 R12: ffffffff828893b0 [26458.347107] R13: ffff880077bc4b60 R14: ffff880077bc4340 R15: ffff880077bc4bb0 [26458.347109] FS: 0000000000000000(0000) GS:ffff88007fc00000(0000) knlGS:0000000000000000 [26458.347110] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b [26458.347111] CR2: 00007f1de825ca08 CR3: 000000007ad1b000 CR4: 00000000000406f0 [26458.347114] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [26458.347115] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [26458.347116] Stack: [26458.347117] 0000000000000000 ffffffff8124dd82 ffff880000000000 0000000000000000 [26458.347119] ffffffff81e587c0 0000000000000292 0000000035c99c30 ffff880061a18fb8 [26458.347121] ffff880077bc4340 ffff880061a18fa0 ffff88007aa18800 ffff880061a18f18 [26458.347123] Call Trace: [26458.347127] [] ? writeback_sb_inodes+0x122/0x5b0 [26458.347131] [] _raw_spin_lock+0x39/0x50 [26458.347133] [] ? writeback_sb_inodes+0x122/0x5b0 [26458.347136] [] ? __cond_resched_lock+0x39/0x90 [26458.347138] [] writeback_sb_inodes+0x122/0x5b0 [26458.347141] [] __writeback_inodes_wb+0xa2/0xd0 [26458.347144] [] wb_writeback+0x40b/0x790 [26458.347146] [] bdi_writeback_workfn+0x144/0x900 [26458.347149] [] ? process_one_work+0x166/0x850 [26458.347152] [] process_one_work+0x1f3/0x850 [26458.347154] [] ? process_one_work+0x166/0x850 [26458.347156] [] worker_thread+0x48/0x4b0 [26458.347159] [] ? process_one_work+0x850/0x850 [26458.347161] [] kthread+0xe4/0x100 [26458.347163] [] ? finish_task_switch+0x7d/0x120 [26458.347165] [] ? kthread_create_on_node+0x220/0x220 [26458.347167] [] ret_from_fork+0x58/0x90 [26458.347169] [] ? kthread_create_on_node+0x220/0x220 So, when I took a look at the writeback_sb_inodes in the latest code, there was a below commit regarding to this issue. Indeed, after I did cherry-pick this patch, the issue was gone. Could you consider merging this patch into v3.18 stable line? commit 590dca3a71875461e8fea3013af74386945191b2 Author: Chris Mason Date: Fri Sep 18 13:35:08 2015 -0400 fs-writeback: unplug before cond_resched in writeback_sb_inodes Thanks,