Re: [PATCH] mm: fix lazy vmap purging (use-after-free error)

[Vegard Nossum <vegard.nossum@gmail.com>]

2009/2/20 Paul E. McKenney <paulmck@linux.vnet.ibm.com>:
> On Fri, Feb 20, 2009 at 03:51:28PM +0100, Vegard Nossum wrote:
>>
>> I added some printks to __free_vmap_area() and rcu_free_va(), and it
>> shows that the kfree() is being called immediately (inside the list
>> traversal). So the call_rcu() is happening immediately (or almost
>> immediately).
>>
>> If I've understood correctly, the RCU processing can happen inside a
>> spinlock, as long as interrupts are enabled. (Won't the timer IRQ
>> trigger softirq processing, which triggers RCU callback processing,
>> for example?)
>>
>> And interrupts are enabled when this happens: EFLAGS: 00000292
>>
>> Please correct me if I am wrong!
>
> If you are using preemptable RCU, and if the read side accesses are not
> protected by rcu_read_lock(), this can happen.  At least for values of
> "immediately" in the millisecond range.
>
> If you were using classic or hierarchical RCU, the fact that the
> call_rcu() is within a spinlock (as opposed to mutex) critical section
> should prevent the grace period from ending.
>
> So, what flavor of RCU were you using?

$ grep RCU .config
# RCU Subsystem
# CONFIG_CLASSIC_RCU is not set
CONFIG_TREE_RCU=y
# CONFIG_PREEMPT_RCU is not set
# CONFIG_RCU_TRACE is not set
CONFIG_RCU_FANOUT=32
# CONFIG_RCU_FANOUT_EXACT is not set
# CONFIG_TREE_RCU_TRACE is not set
# CONFIG_PREEMPT_RCU_TRACE is not set
# CONFIG_RCU_TORTURE_TEST is not set
# CONFIG_RCU_CPU_STALL_DETECTOR is not set

And at boot:

[    0.000000] Initializing CPU#0
[    0.000000] Experimental hierarchical RCU implementation.
[    0.000000] Experimental hierarchical RCU init done.

What I did for this list traversal was to put one print-out in front
of the traversal, one after the traversal, one inside (so it would be
called on each iteration), and one in the RCU callback. It looks
something like this:

[  449.670460] __purge_vmap_area_lazy() list:
[  449.671332] __free_vmap_area(c7806a40)
[  449.674736] __free_vmap_area(c7806a80)
[  449.675441] rcu_free_va(c7806a40)
[  449.677407] __free_vmap_area(c7806ac0)
[  449.680113] rcu_free_va(c7806a80)
[  449.682821] __free_vmap_area(c7806b00)
[  449.684264] rcu_free_va(c7806ac0)
[  449.686525] __free_vmap_area(c7806b40)
[  449.688205] rcu_free_va(c7806b00)

...and goes on for a long time, until something triggers this:

[  449.902253] rcu_free_va(c7839d00)
[  449.903247] WARNING: kmemcheck: Caught 32-bit read from freed
memory (c7839d20)

...and finally:

[  457.580253] __purge_vmap_area_lazy() end
[  457.581201] rcu_free_va(c78974c0)

So this is also what I meant by "immediately": The RCU callbacks are
getting called inside the loop, and they're almost always paired with
the list removal, or lagging one object behind.

My guess is that this code posts "too many callbacks", which would
"force the grace period" according to __call_rcu() in
kernel/rcutree.c. What do you think about this?


Vegard

-- 
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
	-- E. W. Dijkstra, EWD1036