Re: use systemtep to debug TLS var in glibc lib

[David Smith <dsmith at redhat dot com>]

The way to usually improve performance with global variables is use
stats instead of incrementing the variable - the locking situation is
greatly improved. So, change your script to:

probe
process("/home/kemi/git/lib/lib/libpthread.so").statement("pthread_mutex_lock@*pthread_mutex_lock.c:163)
{
  immediate[tid()] <<< 1
}

Then when printing the value of the variable, instead of something like:

  printf("hits: %d\n", immediate[i])

do:

  printf("hits: %d\n", @count(immediate[i]))

On Thu, May 17, 2018 at 6:18 AM, kemi <kemi.wang@intel.com> wrote:
>
> On 2018年05月16日 09:43, kemi wrote:
>> Resend because the previous one is blocked by mail server．．．
>>
>> On 2018年05月16日 09:26, kemi wrote:
>>> Hi, All
>>>    I am using Systemtap to debug Glibc library, and wonder if Systemtap
>>> has the capability to track TLS vars (__thread)? More details are provided
>>> as below.
>>>
>>> Case description:
>>> I would like to track lock statistics for pthread adaptive spin mutex,
>>> e.g. the number of immediate gets, spin gets and the sleeping thread number.
>>> So, I created three TLS vars (e.g. static __thread unsigned long immediate_get)
>>> and hack the code accordingly for that purpose.
>>> When I tried to use "stap -L 'process("/home/kemi/git/lib/lib/libpthread.so")
>>> .statement("pthread_mutex_lock@*pthread_mutex_lock.c:*")' | grep immediate_get"
>>> to check the available debug info. Unfortunately, there is nothing to show in
>>> the terminal. Maybe the systemtap can't debug the TLS vars?
>>> I have no idea about it. To workaround this issue, I use a local variable "local_immediate" to
>>> store the thread local variable "immediate_get" at the entry point of pthread_mutex_lock().
>>> Then I can see the correct output as below:
>>>
>>> root@kemi-desktop:/home/kemi/git/lib/lib# stap  -L 'process("/home/kemi/git/lib/lib/
>>> libpthread.so").statement("pthread_mutex_lock@*pthread_mutex_lock.c:*")' | grep immediate
>>> process("/home/kemi/git/lib/lib/libpthread-2.27.9000.so").statement("__pthread_mutex_lock@
>>> ../nptl/pthread_mutex_lock.c:133") $local_immediate:int $local_spin:int $local_block:
>>> int $mutex:pthread_mutex_t* $type:unsigned int $__PRETTY_FUNCTION__:char const[] const
>>>
>>> And create a mutex.stp script as follow:
>>>   1 #! /usr/bin/env stap
>>>   2
>>>   3 probe
>>>   4 process("/home/kemi/git/lib/lib/libpthread.so").statement("pthread_mutex_lock@*pthread_mutex_lock.c:133")
>>>   5 {
>>>   6             printf("immediate_get:%d.n", $local_immediate);
>>>   7 }
>>>   8
>>>
>
> As TLS vars can't be quoted via "$" symbol, I have another workaround which uses a counter to record for
> every hit.
>
> probe
> process("/home/kemi/git/lib/lib/libpthread.so").statement("pthread_mutex_lock@*pthread_mutex_lock.c:163)
> {
>   immediate[tid()]++
> }
>
> And print the statistics number for each thread when my benchmark is finished.
> But I observed obvious (about 10x)performance regression, the overhead probably caused by calling tid()
> in the handler is intolerable. I will be very appreciated for any suggestion to help reduce this overhead
> to an acceptable level.
>
>>> When I run my benchmark with that script, it complains the follow errors message:
>>> root@kemi-desktop:/home/kemi/git/will-it-scale# stap  mutex.stp -c "/home/kemi/git
>>> /will-it-scale/pthread_mutex3_adaptive_threads -t 2 -s 1" -o mutex.txt
>>> semantic error: while processing probe process("/home/kemi/git/lib/lib/libpthread-
>>> 2.27.9000.so").statement("__pthread_mutex_lock@../nptl/pthread_mutex_lock.c:133")
>>> from: process("/home/kemi/git/lib/lib/libpthread.so").statement("pthread_mutex_lock
>>> @*pthread_mutex_lock.c:133")
>>>
>>> semantic error: unrecognized operation in DWARF expression [0] at 0 (0xe0: 0, 0):
>>> identifier '$local_immediate' at mutex.stp:6:39
>>>         dieoffset: 0x258e8 from unknown debug file for /home/kemi/git/lib/lib/libpthread-2.27.9000.so
>>>         function: __GI___pthread_mutex_lock at ../nptl/pthread_mutex_lock.c:133
>>>         source:                 printf("immediate_get:%d.n", $local_immediate);
>>>                                                              ^
>>>
>>> Pass 2: analysis failed.  [man error::pass2]
>>> Tip: /usr/share/doc/systemtap/README.Debian should help you get started.
>>>
>>> If I change the script to dump other existed local variables, it works well. So
>>> I am confused what I did wrong here?
>>> It's very helpful if you can give me some suggestion, thanks very much!
>>>
>>>
>>> Other info may be useful:
>>> OS: ubuntu 16.06 with 4.4.0-103-generic
>>>
>>> Systemtap installation:
>>> apt-get install systemtap systemtap-runtime
>>> stap-prep (missing kernel-debuginfo package is installed manually)
>>>
>>>
>>> Glibc build:
>>> cd ~/glibc
>>> mkdir compile
>>> cd compile
>>> ../configure --prefix=/home/kemi/git/lib
>>> make -j 16 && make install
>>>
>>>
>>>



-- 
David Smith
Associate Manager
Red Hat