Re: [PATCH] xfs: shutdown xfs_sync_worker before the log

Mark Tinguely
2012-06-14T17:13:15Z

On 06/11/12 18:36, Dave Chinner wrote:
> On Mon, Jun 11, 2012 at 04:11:28PM -0500, Mark Tinguely wrote:
>> On 06/11/12 15:45, Ben Myers wrote:
>> ...
>>
>>> That sounds pretty good. In particular, I think that making the start
>>> and stop of the workqueues correct should be the high priority. I'm not
>>> as concerned about the accuracy of the names, or cleaning up xfs_sync.c
>>> and xfs_iget.c, but cleanups are worth doing too.
>>>
>>> I hit a crash related to the xfslogd workqueue awhile back. Mark has
>>> taken it up, so there might be a little coordination to do with him.
>>>
>>> Regards,
>>> Ben
>>
>> To not leave a teaser out there:
>>
>> PID: 25879 TASK: ffff88012ac20340 CPU: 3 COMMAND: "kworker/3:3"
>> #0 [ffff8801a72af920] machine_kexec at ffffffff810244e9
>> #1 [ffff8801a72af990] crash_kexec at ffffffff8108d053
>> #2 [ffff8801a72afa60] oops_end at ffffffff813ad1b8
>> #3 [ffff8801a72afa90] no_context at ffffffff8102bd48
>> #4 [ffff8801a72afae0] __bad_area_nosemaphore at ffffffff8102c04d
>> #5 [ffff8801a72afb30] bad_area_nosemaphore at ffffffff8102c12e
>> #6 [ffff8801a72afb40] do_page_fault at ffffffff813afaee
>> #7 [ffff8801a72afc50] page_fault at ffffffff813ac635
>> [exception RIP: xlog_assign_tail_lsn_locked+72]
>> RIP: ffffffffa040da68 RSP: ffff8801a72afd00 RFLAGS: 00010246
>> RAX: 0000000000000000 RBX: 0000000000000000 RCX: dead000000200200
>> RDX: ffff88013b32d550 RSI: dead000000100100 RDI: ffff88013b32d550
>> RBP: ffff8801a72afd10 R8: ffff8801a72ae000 R9: 0000000000000000
>> R10: 0000000000000000 R11: 0000000000000000 R12: ffff88013b32d568
>> R13: 0000000000000001 R14: ffff8801a72afd90 R15: ffff88013b32d540
>> ORIG_RAX: ffffffffffffffff CS: 0010 SS: 0018
>> #8 [ffff8801a72afd18] xfs_trans_ail_delete_bulk at ffffffffa0414b2a [xfs]
>> #9 [ffff8801a72afd78] xfs_buf_iodone at ffffffffa04119c7 [xfs]
>> #10 [ffff8801a72afdb8] xfs_buf_do_callbacks at ffffffffa041166c [xfs]
>> #11 [ffff8801a72afdd8] xfs_buf_iodone_callbacks at ffffffffa04117de [xfs]
>> #12 [ffff8801a72afdf8] xfs_buf_iodone_work at ffffffffa03ad7e1 [xfs]
>> #13 [ffff8801a72afe18] process_one_work at ffffffff8104c53b
>> #14 [ffff8801a72afe68] worker_thread at ffffffff8104f0e3
>> #15 [ffff8801a72afee8] kthread at ffffffff8105395e
>> #16 [ffff8801a72aff48] kernel_thread_helper at ffffffff813b3ae4
>>
>> I am just digging through that crash. It appears that xfs_umountfs()
>> did a good job in cleaning the AIL and the m_ddev_targp, but it
>> needs to wait for the xfslogd to be finished before deallocating the
>> log.
>
> It is supposed to be already idle before the log is torn down. The
> log is forced synchronously while flushes remaining CIL items, then
> the AIL is emptied synchronously. That should result in no
> outstanding log operations to be run. Then xfs_log_unmount_write()
> is called, which is supposed to wait for the log write to complete
> before allowing the log to be torn down in xfs_log_unmount(). i.e.
> it is also synchronous.
>
> So the question that needs to be answered is this: what is the
> transaction/checkpoint that is being completed here?
>
>> Since workqueues are cheap, maybe it would be smart to have a
>> per-filesystem xfslogd too.
>
> That's overkill. If all we need is to ensure that we have emptied
> the logd wq, then a synchronous flush is all that is necessary. But
> first we need to find the cause of the above problem, and I'd
> suggest a new thread for that...
>
> Cheers,
>
> Dave.

I know this should be a separate thread, but a quick FYI that the buffer
that is being flushed has the XFS_SB_MAGIC in it. A late dirty of the
superblock from the shutdown process?

--Mark Tinguely.