<div dir="ltr"><div class="gmail_extra"><div class="gmail_quote">[Adding tglx to the cc]</div><div class="gmail_quote"><br></div><div class="gmail_quote">On Mon, Jun 23, 2014 at 8:25 PM, Tejun Heo <span dir="ltr"><<a href="mailto:tj@kernel.org" target="_blank">tj@kernel.org</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex">
Hello,<br>
<div><br>
On Tue, Jun 24, 2014 at 01:02:40PM +1000, Dave Chinner wrote:<br>
> start_flush_work() is effectively a special queue_work()<br>
> implementation, so if if it's not safe to call complete() from the<br>
> workqueue as the above patch implies then this code has the same<br>
> problem.<br>
><br>
> Tejun - is this "do it yourself completion" a known issue w.r.t.<br>
> workqueues? I can't find any documentation that says "don't do<br>
> that" so...?<br>
<br>
</div>It's more complex than using flush_work() but there's nothing<br>
fundamentally wrong with it. A work item is completely unlinked<br>
before its execution starts. It's safe to free the work item once its<br>
work function started, whether through kfree() or returning.<br>
<br>
One difference between flush_work() and manual completion would be<br>
that if the work item gets requeued, flush_work() would wait for the<br>
queued one to finish but given the work item is one-shot this doesn't<br>
make any difference.<br>
<br>
I can see no reason why manual completion would behave differently<br>
from flush_work() in this case.<br></blockquote><div><br></div><div>I went looking for a short trace in my original log to show the problem, and instead found evidence of the second problem. I still like the shorter flush_work call, but that's not my call.</div>
<div><br></div><div>I did find this comment in the process_one_work function. Sounds like this could be better documented.</div>
<div><br></div><div> /*</div><div> * It is permissible to free the struct work_struct from</div><div> * inside the function that is called from it, this we need to</div><div> * take into account for lockdep too. To avoid bogus "held</div>
<div> * lock freed" warnings as well as problems when looking into</div><div> * work->lockdep_map, make a copy and use that here.</div><div> */</div><div><br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex">
<div>
> As I understand it, what then happens is that the workqueue code<br>
> grabs another kworker thread and runs the next work item in it's<br>
> queue. IOWs, work items can block, but doing that does not prevent<br>
> execution of other work items queued on other work queues or even on<br>
> the same work queue. Tejun, did I get that correct?<br>
<br>
</div>Yes, as long as the workqueue is under its @max_active limit and has<br>
access to an existing kworker or can create a new one, it'll start<br>
executing the next work item immediately; however, the guaranteed<br>
level of concurrency is 1 even for WQ_RECLAIM workqueues. IOW, the<br>
work items queued on a workqueue must be able to make forward progress<br>
with single work item if the work items are being depended upon for<br>
memory reclaim.</blockquote><div><br></div><div>I mentioned this to Dave when I initially started this thread, but I'm running a RT patched kernel. I don't see forwards progress. The workqueue is only used in 1 spot (xfs_alloc_wq), and has WQ_MEM_RECLAIM set. I started with a 10,000,000 line trace and pulled out the entries which referenced the workqueue and pool leading up to the lockup.</div>
<div><br></div><div><div> scp-4110 [001] ....1.3 101.184640: workqueue_queue_work: work struct=ffff8803c782d900 function=xfs_bmapi_allocate_worker workqueue=ffff88040c9f5a00 pool=ffff88042dae3fc0 req_cpu=512 cpu=1</div>
<div> scp-4110 [001] ....1.3 101.184641: workqueue_activate_work: work struct ffff8803c782d900</div><div> kworker/1:1-89 [001] ....1.1 101.184883: workqueue_nr_running: pool=ffff88042dae3fc0 nr_running=1</div>
<div> kworker/1:1-89 [001] ....1.. 101.184885: workqueue_execute_start: work struct ffff8803c782d900: function xfs_bmapi_allocate_worker</div><div> irq/44-ahci-275 [001] ....1.5 101.185086: workqueue_queue_work: work struct=ffff8800ae3f01e0 function=xfs_end_io workqueue=ffff88040b459a00 pool=ffff88042dae3fc0 req_cpu=512 cpu=1</div>
<div> irq/44-ahci-275 [001] ....1.5 101.185088: workqueue_activate_work: work struct ffff8800ae3f01e0</div><div> scp-4110 [001] ....1.. 101.187911: xfs_ilock: dev 8:5 ino 0xf9e flags ILOCK_EXCL caller xfs_iomap_write_allocate</div>
<div> scp-4110 [001] ....1.3 101.187914: workqueue_queue_work: work struct=ffff8803c782d900 function=xfs_bmapi_allocate_worker workqueue=ffff88040c9f5a00 pool=ffff88042dae3fc0 req_cpu=512 cpu=1</div><div> scp-4110 [001] ....1.3 101.187915: workqueue_activate_work: work struct ffff8803c782d900</div>
<div> scp-4110 [001] ....1.4 101.187926: workqueue_queue_work: work struct=ffff88040a6a01c8 function=blk_delay_work workqueue=ffff88040c9f4a00 pool=ffff88042dae44c0 req_cpu=512 cpu=1</div><div> scp-4110 [001] ....1.4 101.187926: workqueue_activate_work: work struct ffff88040a6a01c8</div>
<div> kworker/1:1-89 [001] ....1.. 101.187998: workqueue_execute_end: work struct ffff8803c782d900</div><div> kworker/1:1-89 [001] ....1.. 101.188000: workqueue_execute_start: work struct ffff8800ae3f01e0: function xfs_end_io</div>
<div> kworker/1:1-89 [001] ....1.. 101.188001: xfs_ilock: dev 8:5 ino 0xf9e flags ILOCK_EXCL caller xfs_setfilesize</div></div><div><br></div><div>The last work never runs. Hangcheck triggers shortly after.</div>
<div><br></div><div>I spent some more time debugging, and I am seeing that tsk_is_pi_blocked is returning 1 in sched_submit_work (kernel/sched/core.c). It looks like sched_submit_work is not detecting that the worker task is blocked on a mutex.</div>
<div><br></div><div>This looks very RT related right now. I see 2 problems from my reading (and experimentation). The first is that the second worker isn't getting started because tsk_is_pi_blocked is reporting that the task isn't blocked on a mutex. The second is that even if another worker needs to be scheduled because the original worker is blocked on a mutex, we need the pool lock to schedule another worker. The pool lock can be acquired by any CPU, and is a spin_lock. If we end up on the slow path for the pool lock, we hit BUG_ON(rt_mutex_real_waiter(task->pi_blocked_on)) in task_blocks_on_rt_mutex in rtmutex.c. I'm not sure how to deal with either problem.</div>
<div><br></div><div>Hopefully I've got all my facts right... Debugging kernel code is a whole new world from userspace code.</div></div></div><div class="gmail_extra"><br></div><div class="gmail_extra">Thanks!</div>
<div class="gmail_extra">
Austin</div></div>