Re: [PATCH v7 1/4] spinlock: A new lockref structure for lockless update of refcount

[Sedat Dilek <sedat.dilek@gmail.com>]

[-- Attachment #1: Type: text/plain, Size: 7451 bytes --]

On Fri, Aug 30, 2013 at 6:52 PM, Linus Torvalds
<torvalds@linux-foundation.org> wrote:
> On Fri, Aug 30, 2013 at 9:37 AM, Sedat Dilek <sedat.dilek@gmail.com> wrote:
>>
>> Where is this a.out file from or how to generate it?
>
> Oh, that's just the silly threaded test-binary. I don't know what you
> called it.
>
> As to your config options, yesh, you have some expensive stuff.
> DEBUG_OBJECTS and DEBUG_MUTEXES in particular tend to cause lots of
> horrible performance issues. I didn't check if there might be other
> things..
>

I tried w/o DEBUG_OBJECTS and DEBUG_MUTEXES and disabled some
unnecessary debug-options, too (see attached diff).

This is what I get now...

[ TEST-CASE ]

$ ~/src/linux-kernel/linux/tools/perf/perf stat --null --repeat 5
./scripts/t_lockref_from-linus
Total loops: 26480075
Total loops: 27002388
Total loops: 25761463
Total loops: 26877615
Total loops: 27047644

 Performance counter stats for './scripts/t_lockref_from-linus' (5 runs):

      10,008617789 seconds time elapsed
          ( +-  0,07% )


Looks like this is now 10x faster: ~2.66Mloops (debug) VS.
~26.60Mloops (no-debug).

[ PERF-RECORD ]

$ sudo ~/src/linux-kernel/linux/tools/perf/perf record -e cycles:pp
./scripts/t_lockref_from-linus
Total loops: 26601346
[ perf record: Woken up 25 times to write data ]
[ perf record: Captured and wrote 6.100 MB perf.data (~266501 samples) ]

[ PERF-REPORT ]

$ sudo ~/src/linux-kernel/linux/tools/perf/perf report -f

Samples: 159K of event 'cycles:pp', Event count (approx.): 76968896763
 12,79%  t_lockref_from-  [kernel.kallsyms]     [k] irq_return
  4,36%  t_lockref_from-  [kernel.kallsyms]     [k] __ticket_spin_lock
  4,36%  t_lockref_from-  [kernel.kallsyms]     [k] __acct_update_integrals
  4,07%  t_lockref_from-  [kernel.kallsyms]     [k] user_exit
  3,12%  t_lockref_from-  [kernel.kallsyms]     [k] local_clock
  2,83%  t_lockref_from-  [kernel.kallsyms]     [k] lockref_get_or_lock
  2,73%  t_lockref_from-  [kernel.kallsyms]     [k] kmem_cache_alloc
  2,62%  t_lockref_from-  [kernel.kallsyms]     [k] __d_lookup_rcu
  2,53%  t_lockref_from-  libc-2.15.so          [.] __xstat64
  2,53%  t_lockref_from-  [kernel.kallsyms]     [k] kmem_cache_free
  2,28%  t_lockref_from-  [kernel.kallsyms]     [k] path_init
  2,27%  t_lockref_from-  [kernel.kallsyms]     [k] link_path_walk
  1,86%  t_lockref_from-  [kernel.kallsyms]     [k] user_enter
  1,85%  t_lockref_from-  [kernel.kallsyms]     [k] rcu_eqs_exit_common.isra.43
  1,81%  t_lockref_from-  [kernel.kallsyms]     [k] sched_clock_cpu
  1,79%  t_lockref_from-  [kernel.kallsyms]     [k] rcu_eqs_enter_common.isra.45
  1,78%  t_lockref_from-  [kernel.kallsyms]     [k] path_lookupat
  1,67%  t_lockref_from-  [kernel.kallsyms]     [k] native_read_tsc
  1,63%  t_lockref_from-  [kernel.kallsyms]     [k] cp_new_stat
  1,61%  t_lockref_from-  [kernel.kallsyms]     [k] lockref_put_or_lock
  1,53%  t_lockref_from-  [kernel.kallsyms]     [k] account_system_time
  1,48%  t_lockref_from-  [kernel.kallsyms]     [k] tracesys
  1,47%  t_lockref_from-  [kernel.kallsyms]     [k] copy_user_generic_unrolled
  1,46%  t_lockref_from-  [kernel.kallsyms]     [k] syscall_trace_enter
  1,39%  t_lockref_from-  [kernel.kallsyms]     [k] jiffies_to_timeval
  1,33%  t_lockref_from-  [kernel.kallsyms]     [k] native_sched_clock
  1,27%  t_lockref_from-  [kernel.kallsyms]     [k] getname_flags
  1,27%  t_lockref_from-  [kernel.kallsyms]     [k] lookup_fast
  1,18%  t_lockref_from-  [kernel.kallsyms]     [k] get_vtime_delta
  1,05%  t_lockref_from-  [kernel.kallsyms]     [k] syscall_trace_leave
  1,03%  t_lockref_from-  [kernel.kallsyms]     [k] generic_fillattr
  1,02%  t_lockref_from-  [kernel.kallsyms]     [k] strncpy_from_user
  1,00%  t_lockref_from-  [kernel.kallsyms]     [k] user_path_at_empty
  0,97%  t_lockref_from-  [kernel.kallsyms]     [k] account_user_time
  0,95%  t_lockref_from-  [kernel.kallsyms]     [k] vfs_fstatat
  0,95%  t_lockref_from-  [kernel.kallsyms]     [k] system_call_after_swapgs
  0,92%  t_lockref_from-  [kernel.kallsyms]     [k] generic_permission
  0,91%  t_lockref_from-  [kernel.kallsyms]     [k] filename_lookup
  0,80%  t_lockref_from-  [kernel.kallsyms]     [k] vfs_getattr
  0,78%  t_lockref_from-  [kernel.kallsyms]     [k] __ticket_spin_unlock
  0,74%  t_lockref_from-  [kernel.kallsyms]     [k] complete_walk
  0,70%  t_lockref_from-  [kernel.kallsyms]     [k] vtime_account_user
  0,68%  t_lockref_from-  [kernel.kallsyms]     [k] d_rcu_to_refcount
  0,65%  t_lockref_from-  [kernel.kallsyms]     [k] common_perm
  0,62%  t_lockref_from-  [kernel.kallsyms]     [k] rcu_eqs_enter
  0,58%  t_lockref_from-  [kernel.kallsyms]     [k] vtime_user_enter
  0,57%  t_lockref_from-  [kernel.kallsyms]     [k] __inode_permission
  0,55%  t_lockref_from-  [kernel.kallsyms]     [k] dput
  0,52%  t_lockref_from-  [kernel.kallsyms]     [k] apparmor_inode_getattr
  0,52%  t_lockref_from-  [kernel.kallsyms]     [k] SYSC_newstat
  0,52%  t_lockref_from-  [kernel.kallsyms]     [k] mntget
  0,49%  t_lockref_from-  [kernel.kallsyms]     [k] cpuacct_account_field
  0,48%  t_lockref_from-  [kernel.kallsyms]     [k] __vtime_account_system
  0,46%  t_lockref_from-  t_lockref_from-linus  [.] start_routine

Thanks for all the explanations and hints.

Regards,
- Sedat -

P.S.: Some words to "perf -f"...

$ sudo ~/src/linux-kernel/linux/tools/perf/perf record -f -e cycles:pp
./scripts/t_lockref_from-linus
[sudo] password for wearefam:
  Error: unknown switch `f'

 usage: perf record [<options>] [<command>]
    or: perf record [<options>] -- <command> [<options>]

    -e, --event <event>   event selector. use 'perf list' to list
available events
        --filter <filter>
                          event filter
    -p, --pid <pid>       record events on existing process id
    -t, --tid <tid>       record events on existing thread id
    -r, --realtime <n>    collect data with this RT SCHED_FIFO priority
    -D, --no-delay        collect data without buffering
    -R, --raw-samples     collect raw sample records from all opened counters
    -a, --all-cpus        system-wide collection from all CPUs
    -C, --cpu <cpu>       list of cpus to monitor
    -c, --count <n>       event period to sample
    -o, --output <file>   output file name
    -i, --no-inherit      child tasks do not inherit counters
    -F, --freq <n>        profile at this frequency
    -m, --mmap-pages <n>  number of mmap data pages
        --group           put the counters into a counter group
    -g, --call-graph <mode[,dump_size]>
                          do call-graph (stack chain/backtrace)
recording: [fp] dwarf
    -v, --verbose         be more verbose (show counter open errors, etc)
    -q, --quiet           don't print any message
    -s, --stat            per thread counts
    -d, --data            Sample addresses
    -T, --timestamp       Sample timestamps
    -P, --period          Sample period
    -n, --no-samples      don't sample
    -N, --no-buildid-cache
                          do not update the buildid cache
    -B, --no-buildid      do not collect buildids in perf.data
    -G, --cgroup <name>   monitor event in cgroup name only
    -u, --uid <user>      user to profile
    -b, --branch-any      sample any taken branches
    -j, --branch-filter <branch filter mask>
                          branch stack filter modes
    -W, --weight          sample by weight (on special events only)

- EOT -

[-- Attachment #2: kernel-config.diff --]
[-- Type: application/octet-stream, Size: 2837 bytes --]

--- /boot/config-3.11.0-rc7-1-lockref-small	2013-08-30 10:23:42.000000000 +0200
+++ /boot/config-3.11.0-rc7-3-lockref-small	2013-09-01 11:23:21.000000000 +0200
@@ -351,6 +351,7 @@ CONFIG_INLINE_READ_UNLOCK=y
 CONFIG_INLINE_READ_UNLOCK_IRQ=y
 CONFIG_INLINE_WRITE_UNLOCK=y
 CONFIG_INLINE_WRITE_UNLOCK_IRQ=y
+CONFIG_MUTEX_SPIN_ON_OWNER=y
 CONFIG_FREEZER=y
 
 #
@@ -542,11 +543,7 @@ CONFIG_PM_SLEEP_SMP=y
 # CONFIG_PM_WAKELOCKS is not set
 CONFIG_PM_RUNTIME=y
 CONFIG_PM=y
-CONFIG_PM_DEBUG=y
-# CONFIG_PM_ADVANCED_DEBUG is not set
-# CONFIG_PM_TEST_SUSPEND is not set
-CONFIG_PM_SLEEP_DEBUG=y
-# CONFIG_PM_TRACE_RTC is not set
+# CONFIG_PM_DEBUG is not set
 # CONFIG_WQ_POWER_EFFICIENT_DEFAULT is not set
 CONFIG_ACPI=y
 CONFIG_ACPI_SLEEP=y
@@ -1625,9 +1622,8 @@ CONFIG_IWLWIFI_OPMODE_MODULAR=y
 #
 # Debugging Options
 #
-CONFIG_IWLWIFI_DEBUG=y
+# CONFIG_IWLWIFI_DEBUG is not set
 CONFIG_IWLWIFI_DEBUGFS=y
-# CONFIG_IWLWIFI_DEBUG_EXPERIMENTAL_UCODE is not set
 CONFIG_IWLWIFI_DEVICE_TRACING=y
 CONFIG_IWLWIFI_P2P=y
 # CONFIG_IWL4965 is not set
@@ -3181,7 +3177,7 @@ CONFIG_USB_SUPPORT=y
 CONFIG_USB_COMMON=y
 CONFIG_USB_ARCH_HAS_HCD=y
 CONFIG_USB=y
-CONFIG_USB_DEBUG=y
+# CONFIG_USB_DEBUG is not set
 CONFIG_USB_ANNOUNCE_NEW_DEVICES=y
 
 #
@@ -3743,11 +3739,11 @@ CONFIG_EXT4_FS=y
 CONFIG_EXT4_USE_FOR_EXT23=y
 CONFIG_EXT4_FS_POSIX_ACL=y
 CONFIG_EXT4_FS_SECURITY=y
-CONFIG_EXT4_DEBUG=y
+# CONFIG_EXT4_DEBUG is not set
 CONFIG_JBD=y
 # CONFIG_JBD_DEBUG is not set
 CONFIG_JBD2=y
-CONFIG_JBD2_DEBUG=y
+# CONFIG_JBD2_DEBUG is not set
 CONFIG_FS_MBCACHE=y
 # CONFIG_REISERFS_FS is not set
 # CONFIG_JFS_FS is not set
@@ -3955,22 +3951,14 @@ CONFIG_DEBUG_KERNEL=y
 # Memory Debugging
 #
 # CONFIG_DEBUG_PAGEALLOC is not set
-CONFIG_DEBUG_OBJECTS=y
-# CONFIG_DEBUG_OBJECTS_SELFTEST is not set
-# CONFIG_DEBUG_OBJECTS_FREE is not set
-# CONFIG_DEBUG_OBJECTS_TIMERS is not set
-# CONFIG_DEBUG_OBJECTS_WORK is not set
-CONFIG_DEBUG_OBJECTS_RCU_HEAD=y
-# CONFIG_DEBUG_OBJECTS_PERCPU_COUNTER is not set
-CONFIG_DEBUG_OBJECTS_ENABLE_DEFAULT=1
-CONFIG_DEBUG_SLAB=y
-# CONFIG_DEBUG_SLAB_LEAK is not set
+# CONFIG_DEBUG_OBJECTS is not set
+# CONFIG_DEBUG_SLAB is not set
 CONFIG_HAVE_DEBUG_KMEMLEAK=y
 # CONFIG_DEBUG_KMEMLEAK is not set
 # CONFIG_DEBUG_STACK_USAGE is not set
 # CONFIG_DEBUG_VM is not set
 # CONFIG_DEBUG_VIRTUAL is not set
-CONFIG_DEBUG_MEMORY_INIT=y
+# CONFIG_DEBUG_MEMORY_INIT is not set
 # CONFIG_DEBUG_PER_CPU_MAPS is not set
 CONFIG_HAVE_DEBUG_STACKOVERFLOW=y
 # CONFIG_DEBUG_STACKOVERFLOW is not set
@@ -4002,7 +3990,7 @@ CONFIG_TIMER_STATS=y
 # CONFIG_DEBUG_RT_MUTEXES is not set
 # CONFIG_RT_MUTEX_TESTER is not set
 # CONFIG_DEBUG_SPINLOCK is not set
-CONFIG_DEBUG_MUTEXES=y
+# CONFIG_DEBUG_MUTEXES is not set
 # CONFIG_DEBUG_WW_MUTEX_SLOWPATH is not set
 # CONFIG_DEBUG_LOCK_ALLOC is not set
 # CONFIG_PROVE_LOCKING is not set