lock contention - what can we do about it?

[Ciprian Ciubotariu]

On Monday 07 March 2011 01:51:22 Ciprian Ciubotariu wrote:
> The spinlock used for DUChainLock does active waiting, using usleep to yield the CPU from the waiting thread. The amount of time each thread spends on idle should be the time spent in that usleep, plus time spent waiting on other OS sempahores (QMutexes etc.).
> 
> It just came to me that one way of testing the DUChainLock contention is to remove the usleep in class DUChainLock and measure the amount the CPU utilization grows. The actual work won't go faster, since the thread is still waiting, but this time fully utilizing CPU cycles. The rest of the CPU utilization up to 100% (or 200% for 2 CPUs) account for the rest of the locks.
> 
> 


Based on my theory, here are some results:

== With usleep ==

cipi at purple:~/src/kdevelop$ time ./kdevplatform/build/util/duchainify/duchainify -f all-declarations-and-uses-and-AST --verbose --threads 4 /home/cipi/src/kdelibs-4.5.2/
...

real    13m55.279s
user    5m40.480s
sys     0m58.110s





cipi at purple:~/src/kdevelop$ time ./kdevplatform/build/util/duchainify/duchainify -f all-declarations-and-uses-and-AST --verbose --threads 1 /home/cipi/src/kdelibs-4.5.2/
....
processed 21324 out of 21324
ready
pp_macro::definition There were items left on destruction: 139

real    10m45.314s
user    4m36.730s
sys     0m32.660s



== Without usleep ==

cipi at purple:~/src/kdevelop$ time ./kdevplatform/build/util/duchainify/duchainify -f all-declarations-and-uses-and-AST --verbose --threads 4 /home/cipi/src/kdelibs-4.5.2/
....
processed 21324 out of 21324
ready
pp_macro::definition There were items left on destruction: 139

real    11m37.388s
user    21m13.570s
sys     2m19.450s



cipi at purple:~/src/kdevelop$ time ./kdevplatform/build/util/duchainify/duchainify -f all-declarations-and-uses-and-AST --verbose --threads 1 /home/cipi/src/kdelibs-4.5.2/
....
processed 21324 out of 21324
ready
pp_macro::definition There were items left on destruction: 139

real    10m33.508s
user    4m42.330s
sys     0m31.230s


I have also attached the patch for the second part of the test. What happens without usleep is that the waiting thread continuously spins instead of having 500 microseconds (or milliseconds?) delays.

Here is my analysis on the results, done on an 4-core 4GB machine:

1. using usleep, duchainify needs 5 minutes and 40 seconds user-mode and 58 seconds in OS kernel-mode to finish the job. That is with 4 threads. The wall-clock time is 13mins and 55seconds, meaning it actually uses 5m40s/13m55s/4 of the available resources.
2. using usleep, duchainify needs 4m36s user-mode and 32s kernel-mode with 1 processing thread. The wall-time clock decreased to 10m45s, but that might be because the first run cached all files.

From the two facts above we can see that parallelizing duchainify brings no improvement, if not decreases the performance in duchainifying kdelibs.

From this moment I applied the patch and redone the benchmarks with 1 thread and with 4 threads. Now the waits in DUChainLock do consume CPU time

3. With 1 thread duchain needs 4m42 seconds of user-time, 6 seconds higher than the version with usleeps. This negligible difference means the thread never waits on the lock.
4. With 4 threads duchain uses 21m13s, which is rougly 4 times the user-mode time spent in the usleep-enabled version. This means 16 minutes of CPU time is spent spinning in the DUChain. I have no explanation for the increase in system time to 2m19s.

My interpretation is that while one of the threads is processing, the other 3 are waiting for the duchain lock (similar to the BKL - big kernel lock - which serialized spinlocks earlier in the kernel). The waiting was correctly deferred by the usleep to the OS.

Please also note that the wall-clock time needed by this computer to duchainify kde-libs-4.5.2 is approximately the same regardless of the number of threads.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: no-usleep.diff
Type: text/x-patch
Size: 797 bytes
Desc: not available
URL: <http://mail.kde.org/pipermail/kdevelop-devel/attachments/20110309/26491d52/attachment.diff>