Hello,
I've been trying to trace the mmap_lock calls using tracepoints and
captured this behaviour which I cannot explain. This was with the maple
tree v2 patches running ebizzy with multiple threads in an x86_64 KVM
using 8 virtual CPUs.
AFAICT, there are zero callers that use the mmap_lock directly besides a
prefetchw(&mm->mmap_lock);
ebizzy-803 [000] .... 5376.655366: lock_release: 00000000de8cf25e lock
ebizzy-803 [000] .... 5376.655366: lock_release: 00000000b5e38448 ptlock_ptr(page)
ebizzy-803 [000] .... 5376.655367: lock_release: 000000006b581afd &mm->mmap_lock
ebizzy-803 [000] .... 5376.655367: mmap_lock_released: mm=000000001de7b122 memcg_path= write=false
ebizzy-803 [000] .... 5376.655369: mmap_lock_start_locking: mm=000000001de7b122 memcg_path= write=false
ebizzy-803 [000] .... 5376.655369: mmap_lock_acquire_returned: mm=000000001de7b122 memcg_path= write=false success=false
ebizzy-803 [000] .... 5376.655369: mmap_lock_start_locking: mm=000000001de7b122 memcg_path= write=false
ebizzy-803 [000] .... 5376.655369: lock_acquire: 000000006b581afd read &mm->mmap_lock
ebizzy-803 [000] d... 5376.655369: lock_acquire: 00000000984d533e &sem->wait_lock
ebizzy-803 [000] d... 5376.655370: lock_release: 00000000984d533e &sem->wait_lock
ebizzy-803 [000] d... 5376.655370: lock_acquire: 00000000cbb1a456 &rq->__lock
ebizzy-803 [000] d... 5376.655371: lock_acquire: 00000000b3d53a93 read rcu_read_lock
ebizzy-803 [000] d... 5376.655371: lock_release: 00000000b3d53a93 rcu_read_lock
ebizzy-803 [000] d... 5376.655371: lock_acquire: 00000000b3d53a93 read rcu_read_lock
ebizzy-803 [000] d... 5376.655371: lock_release: 00000000b3d53a93 rcu_read_lock
ebizzy-803 [000] d... 5376.655372: lock_acquire: 00000000b3d53a93 read rcu_read_lock
ebizzy-803 [000] d... 5376.655372: lock_release: 00000000b3d53a93 rcu_read_lock
ebizzy-803 [000] d... 5376.655372: lock_release: 00000000cbb1a456 &rq->__lock
<idle>-0 [000] d... 5376.655373: lock_acquire: 00000000cbb1a456 &rq->__lock
<idle>-0 [000] d... 5376.655373: lock_release: 00000000cbb1a456 &rq->__lock
<idle>-0 [000] d... 5376.655373: lock_acquire: 00000000bb7b405b read tk_core.seq.seqcount
<idle>-0 [000] d... 5376.655374: lock_release: 00000000bb7b405b tk_core.seq.seqcount
<idle>-0 [000] d... 5376.655374: lock_acquire: 000000007c3ac380 read jiffies_seq.seqcount
<idle>-0 [000] d... 5376.655374: lock_release: 000000007c3ac380 jiffies_seq.seqcount
<idle>-0 [000] d.h. 5376.655460: lock_acquire: 00000000bb7b405b read tk_core.seq.seqcount
<idle>-0 [000] d.h. 5376.655460: lock_release: 00000000bb7b405b tk_core.seq.seqcount
<idle>-0 [000] d.h. 5376.655460: lock_acquire: 00000000f7c85b8f hrtimer_bases.lock
<idle>-0 [000] d.h. 5376.655461: lock_acquire: 00000000bb7b405b read tk_core.seq.seqcount
<idle>-0 [000] d.h. 5376.655461: lock_release: 00000000bb7b405b tk_core.seq.seqcount
<idle>-0 [000] d.h. 5376.655461: lock_release: 00000000f7c85b8f hrtimer_bases.lock
<idle>-0 [000] d.h. 5376.655462: lock_acquire: 00000000bb7b405b read tk_core.seq.seqcount
<idle>-0 [000] d.h. 5376.655462: lock_release: 00000000bb7b405b tk_core.seq.seqcount
<idle>-0 [000] d.h. 5376.655462: lock_acquire: 00000000cbb1a456 &rq->__lock
<idle>-0 [000] d.h. 5376.655463: lock_release: 00000000cbb1a456 &rq->__lock
<idle>-0 [000] d.h. 5376.655463: lock_acquire: 00000000f7c85b8f hrtimer_bases.lock
<idle>-0 [000] d.h. 5376.655464: lock_release: 00000000f7c85b8f hrtimer_bases.lock
<idle>-0 [000] d.h. 5376.655464: lock_acquire: 00000000bb7b405b read tk_core.seq.seqcount
<idle>-0 [000] d.h. 5376.655464: lock_release: 00000000bb7b405b tk_core.seq.seqcount
<idle>-0 [000] d... 5376.655466: lock_acquire: 00000000bb7b405b read tk_core.seq.seqcount
<idle>-0 [000] d... 5376.655466: lock_release: 00000000bb7b405b tk_core.seq.seqcount
<idle>-0 [000] d... 5376.655467: lock_acquire: 000000007c3ac380 read jiffies_seq.seqcount
<idle>-0 [000] d... 5376.655467: lock_release: 000000007c3ac380 jiffies_seq.seqcount
<idle>-0 [000] d.h. 5376.655488: lock_acquire: 00000000bb7b405b read tk_core.seq.seqcount
<idle>-0 [000] d.h. 5376.655489: lock_release: 00000000bb7b405b tk_core.seq.seqcount
<idle>-0 [000] d.h. 5376.655489: lock_acquire: 00000000cbb1a456 &rq->__lock
<idle>-0 [000] dNh. 5376.655490: lock_release: 00000000cbb1a456 &rq->__lock
<idle>-0 [000] dN.. 5376.655490: lock_acquire: 00000000cbb1a456 &rq->__lock
<idle>-0 [000] d... 5376.655491: lock_release: 00000000cbb1a456 &rq->__lock
ebizzy-803 [000] d... 5376.655491: lock_acquire: 00000000cbb1a456 &rq->__lock
ebizzy-803 [000] d... 5376.655492: lock_release: 00000000cbb1a456 &rq->__lock
ebizzy-803 [000] .... 5376.655492: mmap_lock_acquire_returned: mm=000000001de7b122 memcg_path= write=false success=true
The following tracepoints were enabled:
events/mmap_lock/enable
events/lock/enable
My reading of the above trace is that the ebizzy thread dropped the lock
and immediately attempted to reacquire and detected it was in contention
so the thread added itself to the list and went to sleep only to wake up
and get the lock?
Doesn't that mean the mmap_lock is _not_ contended? The lack of
contention makes sense since there is no tracepoint of an attempt to
acquire the lock between the dropping of the lock and the same MM waking
up to get the lock.
What is even stranger is if I change the value of _Q_PENDING_LOOPS from
(1 << 9) to (1 << 10), the benchmark performs better.
>From the above trace and the effects of the _Q_PENDING_LOOPS change, it
looks like the lock is somehow remaining in a state that causes a
failure to acquire the lock even when it is not held or contended?
Thanks,
Liam
