Message-ID: <20151108114917.GA5620@achernar.madore.org>
Date:	Sun, 8 Nov 2015 12:49:17 +0100
From:	David Madore <david+ml@...ore.org>
To:	Linux Kernel mailing-list <linux-kernel@...r.kernel.org>
Subject: XFS freeze (xfsaild blocked) with 4.2.5 (also 4.3)

Compiled a 4.2.5 kernel a few days ago.  This morning, my machine was
essentially unresponsive (couldn't log on) so I used
alt-sysrq-{s,t,s,u,b} to reboot it, and after reboot it appears that
the first suspicious message concerns xfsaild blocked for more than
300 seconds.  The disks and filesystems are good as far as I know, and
I never had any problem with my previous (4.1.4) kernel, so I guess
this is a regression in 4.2.  (I also had a similar issue with 4.3,
which is probably due to the same cause and also XFS-related: <URL:
https://lkml.org/lkml/2015/11/4/104 >.)

Please contact me for further information, or just to make me feel
less lonely and helpless when facing this kind of bug. :-(

Here are the first few and last lines of log, with links to the full
logs and full config below:

Nov  8 08:08:14 vega kernel: [313800.046048] INFO: task xfsaild/md117:14100 blocked for more than 300 seconds.
Nov  8 08:08:14 vega kernel: [313800.046054]       Not tainted 4.2.5-vega #1
Nov  8 08:08:14 vega kernel: [313800.046057] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov  8 08:08:14 vega kernel: [313800.046060] xfsaild/md117   D ffff88023fc14a00     0 14100      2 0x00000000
Nov  8 08:08:14 vega kernel: [313800.046066]  ffff8800bbb07d18 0000000000000046 ffffffff817244c0 ffff8802345126c0
Nov  8 08:08:14 vega kernel: [313800.046071]  ffff8800bbb07d08 ffffffff810a35ba ffff8800bbb07d58 ffff8800bbb08000
Nov  8 08:08:14 vega kernel: [313800.046075]  ffff880231235528 0000000000000000 ffff880231235400 ffff880234460e00
Nov  8 08:08:14 vega kernel: [313800.046080] Call Trace:
Nov  8 08:08:14 vega kernel: [313800.046090]  [<ffffffff810a35ba>] ? try_to_del_timer_sync+0x4a/0x60
Nov  8 08:08:14 vega kernel: [313800.046095]  [<ffffffff81531692>] schedule+0x32/0x80
Nov  8 08:08:14 vega kernel: [313800.046123]  [<ffffffffa0815724>] _xfs_log_force+0x154/0x240 [xfs]
Nov  8 08:08:14 vega kernel: [313800.046128]  [<ffffffff8106f3c0>] ? wake_up_q+0x70/0x70
Nov  8 08:08:14 vega kernel: [313800.046143]  [<ffffffffa0815835>] xfs_log_force+0x25/0x80 [xfs]
Nov  8 08:08:14 vega kernel: [313800.046159]  [<ffffffffa081f301>] ? xfs_trans_ail_cursor_done+0x11/0x30 [xfs]
Nov  8 08:08:14 vega kernel: [313800.046173]  [<ffffffffa081f4d8>] xfsaild+0x138/0x560 [xfs]
Nov  8 08:08:14 vega kernel: [313800.046188]  [<ffffffffa081f3a0>] ? xfs_trans_ail_cursor_first+0x80/0x80 [xfs]
Nov  8 08:08:14 vega kernel: [313800.046203]  [<ffffffffa081f3a0>] ? xfs_trans_ail_cursor_first+0x80/0x80 [xfs]
Nov  8 08:08:14 vega kernel: [313800.046207]  [<ffffffff81065d54>] kthread+0xc4/0xe0
Nov  8 08:08:14 vega kernel: [313800.046211]  [<ffffffff81065c90>] ? kthread_create_on_node+0x180/0x180
Nov  8 08:08:14 vega kernel: [313800.046215]  [<ffffffff8153495f>] ret_from_fork+0x3f/0x70
Nov  8 08:08:14 vega kernel: [313800.046219]  [<ffffffff81065c90>] ? kthread_create_on_node+0x180/0x180
<snip>
Nov  8 11:18:01 vega kernel: [325187.487839] Showing busy workqueues and worker pools:
Nov  8 11:18:01 vega kernel: [325187.487839] workqueue xfs-log/md117: flags=0x14
Nov  8 11:18:01 vega kernel: [325187.487839]   pwq 3: cpus=1 node=0 flags=0x0 nice=-20 active=2/256
Nov  8 11:18:01 vega kernel: [325187.487839]     pending: xfs_buf_ioend_work [xfs], xfs_log_worker [xfs]
Nov  8 11:18:01 vega kernel: [325187.487839] workqueue xfs-log/md118: flags=0x14
Nov  8 11:18:01 vega kernel: [325187.487839]   pwq 3: cpus=1 node=0 flags=0x0 nice=-20 active=1/256
Nov  8 11:18:01 vega kernel: [325187.487839]     pending: xfs_log_worker [xfs]
Nov  8 11:18:01 vega kernel: [325187.487839] workqueue xfs-log/md115: flags=0x14
Nov  8 11:18:01 vega kernel: [325187.487839]   pwq 3: cpus=1 node=0 flags=0x0 nice=-20 active=1/256
Nov  8 11:18:01 vega kernel: [325187.487839]     pending: xfs_log_worker [xfs]
Nov  8 11:18:01 vega kernel: [325187.487839] workqueue xfs-log/md120: flags=0x14
Nov  8 11:18:01 vega kernel: [325187.487839]   pwq 3: cpus=1 node=0 flags=0x0 nice=-20 active=1/256
Nov  8 11:18:01 vega kernel: [325187.487839]     pending: xfs_log_worker [xfs]
Nov  8 11:18:01 vega kernel: [325187.487839] workqueue xfs-log/md113: flags=0x14
Nov  8 11:18:01 vega kernel: [325187.487839]   pwq 3: cpus=1 node=0 flags=0x0 nice=-20 active=2/256
Nov  8 11:18:01 vega kernel: [325187.487839]     in-flight: 31546:xfs_log_worker [xfs]
Nov  8 11:18:01 vega kernel: [325187.487839]     pending: xfs_buf_ioend_work [xfs]
Nov  8 11:18:01 vega kernel: [325187.487839] workqueue xfs-log/md110: flags=0x14
Nov  8 11:18:01 vega kernel: [325187.487839]   pwq 3: cpus=1 node=0 flags=0x0 nice=-20 active=1/256
Nov  8 11:18:01 vega kernel: [325187.487839]     pending: xfs_log_worker [xfs]
Nov  8 11:18:01 vega kernel: [325187.487839] pool 0: cpus=0 node=0 flags=0x0 nice=0 workers=2 manager: 31448 idle: 31569
Nov  8 11:18:01 vega kernel: [325187.487839] pool 2: cpus=1 node=0 flags=0x0 nice=0 workers=2 manager: 31616 idle: 31510
Nov  8 11:18:01 vega kernel: [325187.487839] pool 3: cpus=1 node=0 flags=0x0 nice=-20 workers=2 manager: 31499
Nov  8 11:18:01 vega kernel: [325187.487839] pool 4: cpus=2 node=0 flags=0x0 nice=0 workers=2 manager: 31503 idle: 31571
Nov  8 11:18:01 vega kernel: [325187.487839] pool 8: cpus=0-3 flags=0x4 nice=0 workers=2 manager: 14279 idle: 31425



Kernel config:
http://www.madore.org/~david/.tmp/config.20151108

Syslog reporting hung tasks and (at 11:18) output of alt-sysrq-t:
http://www.madore.org/~david/.tmp/syslog.20151108

Initial dmesg:
http://www.madore.org/~david/.tmp/dmesg.20151108

-- 
     David A. Madore
   ( http://www.madore.org/~david/ )
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Powered by blists - more mailing lists