public inbox for systemtap@sourceware.org
 help / color / mirror / Atom feed
* [BUG] syscall.unlink no longer works after upgrading kernel to 3.7.3
@ 2013-02-05  6:35 agentzh
  2013-02-05  8:57 ` Mark Wielaard
  0 siblings, 1 reply; 12+ messages in thread
From: agentzh @ 2013-02-05  6:35 UTC (permalink / raw)
  To: systemtap

Hello, folks!

I've been running a systemtap script like this in my test suite:

    probe syscall.unlink {
        if (pid() == target()) {
            println(name, "(", argstr, ")")
        }
    }

The script used to work perfectly fine for many months (with kernel
3.5.x and 3.6.x), but after I upgraded my Linux kernel from 3.6.x to
3.7.3-101 via the Fedora official updates, I started getting this
error:

    semantic error: not accessible at this address [man error::dwarf]
(0xffffffff811a4260, dieoffset: 0x1584359): identifier '$pathname' at
/opt/systemtap/share/systemtap/tapset/linux/syscalls2.stp:3233:30
            source: 	argstr = user_string_quoted($pathname)
                	                            ^

Upgrading systemtap to git master HEAD does not solve the issue:

    $ /opt/systemtap/bin/stap --version
    Systemtap translator/driver (version 2.1/0.154, commit
release-2.0-355-gee68587)
    Copyright (C) 2005-2013 Red Hat, Inc. and others
    This is free software; see the source for copying conditions.
    enabled features: AVAHI LIBRPM LIBSQLITE3 NSS BOOST_SHARED_PTR
TR1_UNORDERED_MAP NLS

Any help to solve this issue will be highly appreciated!

Thanks in advance!

Best regards,
-agentzh

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] syscall.unlink no longer works after upgrading kernel to 3.7.3
  2013-02-05  6:35 [BUG] syscall.unlink no longer works after upgrading kernel to 3.7.3 agentzh
@ 2013-02-05  8:57 ` Mark Wielaard
  2013-02-05 17:30   ` Josh Stone
  0 siblings, 1 reply; 12+ messages in thread
From: Mark Wielaard @ 2013-02-05  8:57 UTC (permalink / raw)
  To: agentzh; +Cc: systemtap

Hi,

On Mon, 2013-02-04 at 22:34 -0800, agentzh wrote:
> The script used to work perfectly fine for many months (with kernel
> 3.5.x and 3.6.x), but after I upgraded my Linux kernel from 3.6.x to
> 3.7.3-101 via the Fedora official updates, I started getting this
> error:
> 
>     semantic error: not accessible at this address [man error::dwarf]
> (0xffffffff811a4260, dieoffset: 0x1584359): identifier '$pathname' at
> /opt/systemtap/share/systemtap/tapset/linux/syscalls2.stp:3233:30
>             source: 	argstr = user_string_quoted($pathname)
>                 	                            ^

I believe Fedora uses GCC 4.7 and compiles in support for ftrace. That
combination seems to trigger the following GCC bug:
http://gcc.gnu.org/bugzilla/show_bug.cgi?id=54793

Perf seems to have a workaround for this issue:
https://lkml.org/lkml/2012/10/3/187

+	if (fentry && (dwarf_tag(vr_die) == DW_TAG_formal_parameter) &&
+	    (dwarf_getlocation_addr(&attr, addr, &op, &nops, 1) == 0))
+		/*
+		 * Workaround: GCC -mfentry option generates odd
+		 * variable location entries which start from a
+		 * function entry+5, even if it is a formal_parameter.
+		 * On the other hand, for functions without fentry call
+		 * (e.g. notrace function), the formal_parameter location
+		 * starts from the function entry address.
+		 * Here, if we find a formal_parameter which doesn't
+		 * start from the function entry, but from function
+		 * entry+5, it should be a buggy entry.
+		 * We forcibly get the variable(parameter) location
+		 * information from entry+5.
+		 */
+		addr += 5;

That seems a little crude, but maybe we can do something like that in
systemtap too with some special flag?

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] syscall.unlink no longer works after upgrading kernel to 3.7.3
  2013-02-05  8:57 ` Mark Wielaard
@ 2013-02-05 17:30   ` Josh Stone
  2013-05-28 18:53     ` Zheng Da
  0 siblings, 1 reply; 12+ messages in thread
From: Josh Stone @ 2013-02-05 17:30 UTC (permalink / raw)
  To: Mark Wielaard; +Cc: agentzh, systemtap

On 02/05/2013 12:57 AM, Mark Wielaard wrote:
> Perf seems to have a workaround for this issue:
> https://lkml.org/lkml/2012/10/3/187
> 
> +	if (fentry && (dwarf_tag(vr_die) == DW_TAG_formal_parameter) &&
> +	    (dwarf_getlocation_addr(&attr, addr, &op, &nops, 1) == 0))
> +		/*
> +		 * Workaround: GCC -mfentry option generates odd
> +		 * variable location entries which start from a
> +		 * function entry+5, even if it is a formal_parameter.
> +		 * On the other hand, for functions without fentry call
> +		 * (e.g. notrace function), the formal_parameter location
> +		 * starts from the function entry address.
> +		 * Here, if we find a formal_parameter which doesn't
> +		 * start from the function entry, but from function
> +		 * entry+5, it should be a buggy entry.
> +		 * We forcibly get the variable(parameter) location
> +		 * information from entry+5.
> +		 */
> +		addr += 5;
> 
> That seems a little crude, but maybe we can do something like that in
> systemtap too with some special flag?

Aha!  Frank and I were just talking about workarounds for this
yesterday, and what perf has done here is pretty much what I had in
mind.  The offset +5 is very arch-specific, of course, for an x86 call.

The other relevant bug is on Fedora's gcc:
https://bugzilla.redhat.com/show_bug.cgi?id=896741

As soon as the upstream gcc fix is confirmed and backported to Fedora,
we'll get the kernel folks to spin a new build on it.  In the meantime
though, I wouldn't mind a heuristic similar to perf's.

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] syscall.unlink no longer works after upgrading kernel to 3.7.3
  2013-02-05 17:30   ` Josh Stone
@ 2013-05-28 18:53     ` Zheng Da
  2013-05-28 19:15       ` Mark Wielaard
  0 siblings, 1 reply; 12+ messages in thread
From: Zheng Da @ 2013-05-28 18:53 UTC (permalink / raw)
  To: Josh Stone; +Cc: Mark Wielaard, agentzh, systemtap

Hello,

I think I got a very similar error in Ubuntu:
semantic error: not accessible at this address [man error::dwarf]
(0xffffffff81480e80, dieoffset: 0x43d730b): identifier '$sdev' at
:10:6
        source:  if ($sdev->host->host_no == 9 && $sdev->id == 1) {
                     ^
I use Linux v3.8.12, and gcc version is 4.6.3.
Is there any better fix for this problem? I checked the workaround for
perf, but I don't know how to apply it to systemtap.

Thanks,
Da

On Tue, Feb 5, 2013 at 12:29 PM, Josh Stone <jistone@redhat.com> wrote:
> On 02/05/2013 12:57 AM, Mark Wielaard wrote:
>> Perf seems to have a workaround for this issue:
>> https://lkml.org/lkml/2012/10/3/187
>>
>> +     if (fentry && (dwarf_tag(vr_die) == DW_TAG_formal_parameter) &&
>> +         (dwarf_getlocation_addr(&attr, addr, &op, &nops, 1) == 0))
>> +             /*
>> +              * Workaround: GCC -mfentry option generates odd
>> +              * variable location entries which start from a
>> +              * function entry+5, even if it is a formal_parameter.
>> +              * On the other hand, for functions without fentry call
>> +              * (e.g. notrace function), the formal_parameter location
>> +              * starts from the function entry address.
>> +              * Here, if we find a formal_parameter which doesn't
>> +              * start from the function entry, but from function
>> +              * entry+5, it should be a buggy entry.
>> +              * We forcibly get the variable(parameter) location
>> +              * information from entry+5.
>> +              */
>> +             addr += 5;
>>
>> That seems a little crude, but maybe we can do something like that in
>> systemtap too with some special flag?
>
> Aha!  Frank and I were just talking about workarounds for this
> yesterday, and what perf has done here is pretty much what I had in
> mind.  The offset +5 is very arch-specific, of course, for an x86 call.
>
> The other relevant bug is on Fedora's gcc:
> https://bugzilla.redhat.com/show_bug.cgi?id=896741
>
> As soon as the upstream gcc fix is confirmed and backported to Fedora,
> we'll get the kernel folks to spin a new build on it.  In the meantime
> though, I wouldn't mind a heuristic similar to perf's.

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] syscall.unlink no longer works after upgrading kernel to 3.7.3
  2013-05-28 18:53     ` Zheng Da
@ 2013-05-28 19:15       ` Mark Wielaard
  2013-05-28 19:57         ` Zheng Da
  0 siblings, 1 reply; 12+ messages in thread
From: Mark Wielaard @ 2013-05-28 19:15 UTC (permalink / raw)
  To: Zheng Da; +Cc: Josh Stone, agentzh, systemtap

On Tue, May 28, 2013 at 02:52:48PM -0400, Zheng Da wrote:
> I think I got a very similar error in Ubuntu:
> semantic error: not accessible at this address [man error::dwarf]
> (0xffffffff81480e80, dieoffset: 0x43d730b): identifier '$sdev' at
> :10:6
>         source:  if ($sdev->host->host_no == 9 && $sdev->id == 1) {
>                      ^
> I use Linux v3.8.12, and gcc version is 4.6.3.
> Is there any better fix for this problem? I checked the workaround for
> perf, but I don't know how to apply it to systemtap.

I believe the patch/commit you are looking for is:

commit 45b02a36c31d857a0a7d17fc86e1b4e9d15df680
Author: Frank Ch. Eigler <fche@redhat.com>
Date:   Tue Feb 12 21:32:30 2013 -0500

    PR15123: work around broken gcc debuginfo for -mfentry functions
    
    http://gcc.gnu.org/bugzilla/show_bug.cgi?id=54793 interferes with the
    calm zen-like state of probing function parameters in programs built
    with CFLAGS=-mfentry, due to a dwarf location-list problem.  This
    patch adds a heuristic function dwflpp::pr15123_retry_addr() that
    offers callers a post-mfentry-address alternative for locating
    variables.  Will they use it, or not?  Join us next week, as our
    heroes encounter ... angry mr. dwarf, five steps away.
    
    * dwflpp.cxx (pr15123_retry_addr): New function.
      (translate_location): Call it, in order to enable $var
      and $$parms resolution.
    * tapsets.cxx (saveargs): Call it, in order to enable
      stap -L <probe> listings.

http://sourceware.org/git/?p=systemtap.git;a=patch;h=45b02a36c31d857a0a7d17fc86e1b4e9d15df680

Cheers,

Mark

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] syscall.unlink no longer works after upgrading kernel to 3.7.3
  2013-05-28 19:15       ` Mark Wielaard
@ 2013-05-28 19:57         ` Zheng Da
  2013-05-28 20:22           ` Josh Stone
  0 siblings, 1 reply; 12+ messages in thread
From: Zheng Da @ 2013-05-28 19:57 UTC (permalink / raw)
  To: Mark Wielaard; +Cc: Josh Stone, agentzh, systemtap

Sorry, I forgot to mention the version of systemtap I'm using.
I'm using v2.2.1. I checked its source code and the patch you
mentioned has been applied.
Does the patch only work with gcc 4.7?

Da

On Tue, May 28, 2013 at 3:14 PM, Mark Wielaard <mjw@redhat.com> wrote:
> On Tue, May 28, 2013 at 02:52:48PM -0400, Zheng Da wrote:
>> I think I got a very similar error in Ubuntu:
>> semantic error: not accessible at this address [man error::dwarf]
>> (0xffffffff81480e80, dieoffset: 0x43d730b): identifier '$sdev' at
>> :10:6
>>         source:  if ($sdev->host->host_no == 9 && $sdev->id == 1) {
>>                      ^
>> I use Linux v3.8.12, and gcc version is 4.6.3.
>> Is there any better fix for this problem? I checked the workaround for
>> perf, but I don't know how to apply it to systemtap.
>
> I believe the patch/commit you are looking for is:
>
> commit 45b02a36c31d857a0a7d17fc86e1b4e9d15df680
> Author: Frank Ch. Eigler <fche@redhat.com>
> Date:   Tue Feb 12 21:32:30 2013 -0500
>
>     PR15123: work around broken gcc debuginfo for -mfentry functions
>
>     http://gcc.gnu.org/bugzilla/show_bug.cgi?id=54793 interferes with the
>     calm zen-like state of probing function parameters in programs built
>     with CFLAGS=-mfentry, due to a dwarf location-list problem.  This
>     patch adds a heuristic function dwflpp::pr15123_retry_addr() that
>     offers callers a post-mfentry-address alternative for locating
>     variables.  Will they use it, or not?  Join us next week, as our
>     heroes encounter ... angry mr. dwarf, five steps away.
>
>     * dwflpp.cxx (pr15123_retry_addr): New function.
>       (translate_location): Call it, in order to enable $var
>       and $$parms resolution.
>     * tapsets.cxx (saveargs): Call it, in order to enable
>       stap -L <probe> listings.
>
> http://sourceware.org/git/?p=systemtap.git;a=patch;h=45b02a36c31d857a0a7d17fc86e1b4e9d15df680
>
> Cheers,
>
> Mark

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] syscall.unlink no longer works after upgrading kernel to 3.7.3
  2013-05-28 19:57         ` Zheng Da
@ 2013-05-28 20:22           ` Josh Stone
  2013-05-28 20:32             ` Mark Wielaard
  0 siblings, 1 reply; 12+ messages in thread
From: Josh Stone @ 2013-05-28 20:22 UTC (permalink / raw)
  To: Zheng Da; +Cc: Mark Wielaard, agentzh, systemtap

On 05/28/2013 12:56 PM, Zheng Da wrote:
> Sorry, I forgot to mention the version of systemtap I'm using.
> I'm using v2.2.1. I checked its source code and the patch you
> mentioned has been applied.
> Does the patch only work with gcc 4.7?

I'm not sure if the -mfentry bug afflicted earlier gcc, but if so that
patch should work just as well.

But there are other reasons for "not accessible" errors, as described in
"man error::dwarf".  Just optimization or inlining can be enough to make
variables unavailable from certain addresses.

Are you able to look at the DWARF dump to see where that variable can be
reached?  The specific symptom of -mfentry is that the locations don't
start until exactly 5 bytes after the start of the function.

It would also help if you gave us your script code snippet that led to
the error.  By $sdev, I'm guessing this is a scsi probe - but I can't
find that exact line in our scsi tapset, so I guess this is your code.


Josh

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] syscall.unlink no longer works after upgrading kernel to 3.7.3
  2013-05-28 20:22           ` Josh Stone
@ 2013-05-28 20:32             ` Mark Wielaard
  2013-05-28 21:36               ` Zheng Da
  0 siblings, 1 reply; 12+ messages in thread
From: Mark Wielaard @ 2013-05-28 20:32 UTC (permalink / raw)
  To: Josh Stone; +Cc: Zheng Da, agentzh, systemtap

On Tue, May 28, 2013 at 01:22:21PM -0700, Josh Stone wrote:
> But there are other reasons for "not accessible" errors, as described in
> "man error::dwarf".  Just optimization or inlining can be enough to make
> variables unavailable from certain addresses.
> 
> Are you able to look at the DWARF dump to see where that variable can be
> reached?

See also http://sourceware.org/systemtap/wiki/TipContextVariables
for some hints and tips on tracking down what could be the real issue.

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] syscall.unlink no longer works after upgrading kernel to 3.7.3
  2013-05-28 20:32             ` Mark Wielaard
@ 2013-05-28 21:36               ` Zheng Da
  2013-05-28 22:51                 ` Josh Stone
  0 siblings, 1 reply; 12+ messages in thread
From: Zheng Da @ 2013-05-28 21:36 UTC (permalink / raw)
  To: Mark Wielaard; +Cc: Josh Stone, agentzh, systemtap

Yes, it's my own script. Here is the code:
probe kernel.function("scsi_device_unbusy") {
    if ($sdev->host->host_no == 9 && $sdev->id == 1) {
        printf("sdev on node %d, host on node %d\n",
addr_to_node($sdev), addr_to_node($sdev->host));
        exit();
    }
}
The script works in Linux 3.2.12.

systemtap actually can find the right location of scsi_device_unbusy,
but it doesn't show its parameters.
$ stap -L 'kernel.function("scsi_device_unbusy")'
kernel.function("scsi_device_unbusy@drivers/scsi/scsi_lib.c:318")

I run eu-readelf -N --debug-dump=info
/usr/lib/debug/lib/modules/3.8.12/vmlinux and the info of
scsi_device_unbusy is shown below:
 [43d72e9]    subprogram
             external             (flag) Yes
             name                 (strp) "scsi_device_unbusy"
             decl_file            (data1) 1
             decl_line            (data2) 318
             prototyped           (flag) Yes
             low_pc               (addr) 0xffffffff81480e80
             high_pc              (addr) 0xffffffff81480f44
             frame_base           (data4) location list [e061d3]
             sibling              (ref4) [43d7492]
 [43d730b]      formal_parameter
               name                 (strp) "sdev"
               decl_file            (data1) 1
               decl_line            (data2) 318
               type                 (ref4) [43d22ff]
               location             (data4) location list [e06233]
 [43d731b]      variable
               name                 (strp) "shost"
               decl_file            (data1) 1
               decl_line            (data2) 320
               type                 (ref4) [43d286d]
               location             (data4) location list [e06269]
 [43d732b]      variable
               name                 (strp) "starget"
               decl_file            (data1) 1
               decl_line            (data2) 321
               type                 (ref4) [43d29be]
 [43d7337]      variable
               name                 (strp) "flags"
               decl_file            (data1) 1
               decl_line            (data2) 322
               type                 (ref4) [43c2d16]
               location             (data4) location list [e062b4]
It seems the function isn't inlined and eu-readelf can read all right
info of its parameter.

Right now the OS has debug info of two kernels.
$ ls /usr/lib/debug/lib/modules/
3.2.30  3.8.12
When the OS uses kernel v3.8.12, stap can still read the right info of
scsi_device_unbusy if I specify version 3.2.30.
$ stap -r 3.2.30 -L 'kernel.function("scsi_device_unbusy")'
kernel.function("scsi_device_unbusy@drivers/scsi/scsi_lib.c:302")
$sdev:struct scsi_device*

I built kernel 3.8.12 with debug info in the same way as I did with
3.2.30. I checked the config file of kernel 3.8.12, all configs
mentioned in http://sourceware.org/systemtap/wiki/SystemTapWithSelfBuiltKernel
has been enabled.
Basically, I run the following in Ubuntu.
fakeroot make-kpkg -j8 --initrd --revision=1.0 kernel_image kernel_debug

Josh, when you say "DWARF dump", do you mean the output of eu-readelf
as I did above?

Thanks,
Da

On Tue, May 28, 2013 at 4:32 PM, Mark Wielaard <mjw@redhat.com> wrote:
> On Tue, May 28, 2013 at 01:22:21PM -0700, Josh Stone wrote:
>> But there are other reasons for "not accessible" errors, as described in
>> "man error::dwarf".  Just optimization or inlining can be enough to make
>> variables unavailable from certain addresses.
>>
>> Are you able to look at the DWARF dump to see where that variable can be
>> reached?
>
> See also http://sourceware.org/systemtap/wiki/TipContextVariables
> for some hints and tips on tracking down what could be the real issue.

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] syscall.unlink no longer works after upgrading kernel to 3.7.3
  2013-05-28 21:36               ` Zheng Da
@ 2013-05-28 22:51                 ` Josh Stone
  2013-05-28 23:52                   ` Zheng Da
  0 siblings, 1 reply; 12+ messages in thread
From: Josh Stone @ 2013-05-28 22:51 UTC (permalink / raw)
  To: Zheng Da; +Cc: Mark Wielaard, agentzh, systemtap

On 05/28/2013 02:35 PM, Zheng Da wrote:
> Yes, it's my own script. Here is the code:
> probe kernel.function("scsi_device_unbusy") {
>     if ($sdev->host->host_no == 9 && $sdev->id == 1) {
>         printf("sdev on node %d, host on node %d\n",
> addr_to_node($sdev), addr_to_node($sdev->host));
>         exit();
>     }
> }
> The script works in Linux 3.2.12.

Ok, this also works on 3.9.2-200.fc18.x86_64.  I don't hit that
particular host_no+id on my machine, but it is hitting the probe.

> systemtap actually can find the right location of scsi_device_unbusy,
> but it doesn't show its parameters.
> $ stap -L 'kernel.function("scsi_device_unbusy")'
> kernel.function("scsi_device_unbusy@drivers/scsi/scsi_lib.c:318")
> 
> I run eu-readelf -N --debug-dump=info
> /usr/lib/debug/lib/modules/3.8.12/vmlinux and the info of
> scsi_device_unbusy is shown below:
>  [43d72e9]    subprogram
>              external             (flag) Yes
>              name                 (strp) "scsi_device_unbusy"
>              decl_file            (data1) 1
>              decl_line            (data2) 318
>              prototyped           (flag) Yes
>              low_pc               (addr) 0xffffffff81480e80
>              high_pc              (addr) 0xffffffff81480f44
>              frame_base           (data4) location list [e061d3]
>              sibling              (ref4) [43d7492]
>  [43d730b]      formal_parameter
>                name                 (strp) "sdev"
>                decl_file            (data1) 1
>                decl_line            (data2) 318
>                type                 (ref4) [43d22ff]
>                location             (data4) location list [e06233]
...
> Josh, when you say "DWARF dump", do you mean the output of eu-readelf
> as I did above?

Yep, that's great.  Next, can you try --debug-dump=loc and see the list
at [e06233] for sdev?  This will hopefully reveal why it's not
available.  On my Fedora 18 kernel, I get:

>  [3b28227]    subprogram
>              external             (flag_present) Yes
>              name                 (strp) "scsi_device_unbusy"
>              decl_file            (data1) 1
>              decl_line            (data2) 323
>              prototyped           (flag_present) Yes
>              low_pc               (addr) 0xffffffff81420310
>              high_pc              (addr) 0xffffffff814203d4
>              frame_base           (exprloc) 
>               [   0] call_frame_cfa
>              GNU_all_call_sites   (flag_present) Yes
>              sibling              (ref4) [3b28405]
>  [3b28245]      formal_parameter
>                name                 (strp) "sdev"
>                decl_file            (data1) 1
>                decl_line            (data2) 323
>                type                 (ref4) [3b22271]
>                location             (sec_offset) location list [d6aa75]
...
>  [d6aa75]  0xffffffff81420315..0xffffffff8142033f [   0] reg5
>            0xffffffff8142033f..0xffffffff814203a6 [   0] reg3
>            0xffffffff814203a6..0xffffffff814203b4 [   0] GNU_entry_value:
>        [   0] reg5
>                                                   [   3] stack_value
>            0xffffffff814203b4..0xffffffff814203d4 [   0] reg3

You can see that my function starts at 420310, yet sdev is first
specified at 420315.  That's the 5-byte fentry call still padding it
away from the start, also seen in objdump -d:

> ffffffff81420310 <scsi_device_unbusy>:
> ffffffff81420310:	e8 eb 92 24 00       	callq  ffffffff81669600 <__fentry__>
> ffffffff81420315:	55                   	push   %rbp
> ffffffff81420316:	48 89 e5             	mov    %rsp,%rbp
> ffffffff81420319:	48 83 ec 20          	sub    $0x20,%rsp

But in my case, the heuristic of stap 45b02a36 appears to be working.  I
can also set environment PR15123_DISABLE=1, and it will fail the same as
for you.  Perhaps you could step through dwflpp::pr15123_retry_addr, and
see what's happening?

My best guess at this point is the check for "-mfentry" in
DW_AT_producer.  I found a Yocto commit where they forced gcc to have
-grecord-gcc-switches, exactly for SystemTap's benefit, but then I'm not
sure why Fedora is able to manage without that option.

http://git.yoctoproject.org/cgit/cgit.cgi/linux-yocto-3.8/commit/?h=standard/base&id=d9a45e3325030f7bd6f37947a7a0b12da7f602c3

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] syscall.unlink no longer works after upgrading kernel to 3.7.3
  2013-05-28 22:51                 ` Josh Stone
@ 2013-05-28 23:52                   ` Zheng Da
  2013-05-29  0:19                     ` Josh Stone
  0 siblings, 1 reply; 12+ messages in thread
From: Zheng Da @ 2013-05-28 23:52 UTC (permalink / raw)
  To: Josh Stone; +Cc: Mark Wielaard, agentzh, systemtap

Hello,

On Tue, May 28, 2013 at 6:51 PM, Josh Stone <jistone@redhat.com> wrote:
> On 05/28/2013 02:35 PM, Zheng Da wrote:
>> Yes, it's my own script. Here is the code:
>> probe kernel.function("scsi_device_unbusy") {
>>     if ($sdev->host->host_no == 9 && $sdev->id == 1) {
>>         printf("sdev on node %d, host on node %d\n",
>> addr_to_node($sdev), addr_to_node($sdev->host));
>>         exit();
>>     }
>> }
>> The script works in Linux 3.2.12.
>
> Ok, this also works on 3.9.2-200.fc18.x86_64.  I don't hit that
> particular host_no+id on my machine, but it is hitting the probe.
>
>> systemtap actually can find the right location of scsi_device_unbusy,
>> but it doesn't show its parameters.
>> $ stap -L 'kernel.function("scsi_device_unbusy")'
>> kernel.function("scsi_device_unbusy@drivers/scsi/scsi_lib.c:318")
>>
>> I run eu-readelf -N --debug-dump=info
>> /usr/lib/debug/lib/modules/3.8.12/vmlinux and the info of
>> scsi_device_unbusy is shown below:
>>  [43d72e9]    subprogram
>>              external             (flag) Yes
>>              name                 (strp) "scsi_device_unbusy"
>>              decl_file            (data1) 1
>>              decl_line            (data2) 318
>>              prototyped           (flag) Yes
>>              low_pc               (addr) 0xffffffff81480e80
>>              high_pc              (addr) 0xffffffff81480f44
>>              frame_base           (data4) location list [e061d3]
>>              sibling              (ref4) [43d7492]
>>  [43d730b]      formal_parameter
>>                name                 (strp) "sdev"
>>                decl_file            (data1) 1
>>                decl_line            (data2) 318
>>                type                 (ref4) [43d22ff]
>>                location             (data4) location list [e06233]
> ...
>> Josh, when you say "DWARF dump", do you mean the output of eu-readelf
>> as I did above?
>
> Yep, that's great.  Next, can you try --debug-dump=loc and see the list
> at [e06233] for sdev?  This will hopefully reveal why it's not
> available.  On my Fedora 18 kernel, I get:
>
>>  [3b28227]    subprogram
>>              external             (flag_present) Yes
>>              name                 (strp) "scsi_device_unbusy"
>>              decl_file            (data1) 1
>>              decl_line            (data2) 323
>>              prototyped           (flag_present) Yes
>>              low_pc               (addr) 0xffffffff81420310
>>              high_pc              (addr) 0xffffffff814203d4
>>              frame_base           (exprloc)
>>               [   0] call_frame_cfa
>>              GNU_all_call_sites   (flag_present) Yes
>>              sibling              (ref4) [3b28405]
>>  [3b28245]      formal_parameter
>>                name                 (strp) "sdev"
>>                decl_file            (data1) 1
>>                decl_line            (data2) 323
>>                type                 (ref4) [3b22271]
>>                location             (sec_offset) location list [d6aa75]
> ...
>>  [d6aa75]  0xffffffff81420315..0xffffffff8142033f [   0] reg5
>>            0xffffffff8142033f..0xffffffff814203a6 [   0] reg3
>>            0xffffffff814203a6..0xffffffff814203b4 [   0] GNU_entry_value:
>>        [   0] reg5
>>                                                   [   3] stack_value
>>            0xffffffff814203b4..0xffffffff814203d4 [   0] reg3
>
> You can see that my function starts at 420310, yet sdev is first
> specified at 420315.  That's the 5-byte fentry call still padding it
> away from the start, also seen in objdump -d:
>
>> ffffffff81420310 <scsi_device_unbusy>:
>> ffffffff81420310:     e8 eb 92 24 00          callq  ffffffff81669600 <__fentry__>
>> ffffffff81420315:     55                      push   %rbp
>> ffffffff81420316:     48 89 e5                mov    %rsp,%rbp
>> ffffffff81420319:     48 83 ec 20             sub    $0x20,%rsp

I think I can also see the 5-byte difference here.

 [e061d3]  0xffffffff81480e80..0xffffffff81480e86 [   0] breg7 8
           0xffffffff81480e86..0xffffffff81480e89 [   0] breg7 16
           0xffffffff81480e89..0xffffffff81480f43 [   0] breg6 16
           0xffffffff81480f43..0xffffffff81480f44 [   0] breg7 8
 [e06233]  0xffffffff81480e85..0xffffffff81480eae [   0] reg5
           0xffffffff81480edf..0xffffffff81480f36 [   0] reg3
 [e06269]  0xffffffff81480ea3..0xffffffff81480eae [   0] breg5 0
           0xffffffff81480eae..0xffffffff81480eb2 [   0] breg3 0
           0xffffffff81480eb2..0xffffffff81480f3e [   0] reg13

Output of objdump -d:
ffffffff81480e80 <scsi_device_unbusy>:
ffffffff81480e80:       e8 7b 6c 22 00          callq
ffffffff816a7b00 <__fentry__>
ffffffff81480e85:       55                      push   %rbp
ffffffff81480e86:       48 89 e5                mov    %rsp,%rbp
ffffffff81480e89:       48 83 ec 20             sub    $0x20,%rsp

>
> But in my case, the heuristic of stap 45b02a36 appears to be working.  I
> can also set environment PR15123_DISABLE=1, and it will fail the same as
> for you.  Perhaps you could step through dwflpp::pr15123_retry_addr, and
> see what's happening?
>
> My best guess at this point is the check for "-mfentry" in
> DW_AT_producer.  I found a Yocto commit where they forced gcc to have
> -grecord-gcc-switches, exactly for SystemTap's benefit, but then I'm not
> sure why Fedora is able to manage without that option.
>
> http://git.yoctoproject.org/cgit/cgit.cgi/linux-yocto-3.8/commit/?h=standard/base&id=d9a45e3325030f7bd6f37947a7a0b12da7f602c3
>
I added lines in the source code of systemtap to print msg when
dwflpp::pr15123_retry_addr returns 0.
The problem is that the producer string returned by
dwarf_formstring(&cudie_producer) is "GNU C 4.6.3". There isn't
"-mfentry". I guess that is what you mean.
Do you want me to use -grecord-gcc-switches to rebuilt the kernel?

Thanks,
Da

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] syscall.unlink no longer works after upgrading kernel to 3.7.3
  2013-05-28 23:52                   ` Zheng Da
@ 2013-05-29  0:19                     ` Josh Stone
  0 siblings, 0 replies; 12+ messages in thread
From: Josh Stone @ 2013-05-29  0:19 UTC (permalink / raw)
  To: Zheng Da; +Cc: Mark Wielaard, agentzh, systemtap

On 05/28/2013 04:52 PM, Zheng Da wrote:
>>>  [43d72e9]    subprogram
>>>              external             (flag) Yes
>>>              name                 (strp) "scsi_device_unbusy"
>>>              decl_file            (data1) 1
>>>              decl_line            (data2) 318
>>>              prototyped           (flag) Yes
>>>              low_pc               (addr) 0xffffffff81480e80
>>>              high_pc              (addr) 0xffffffff81480f44
>>>              frame_base           (data4) location list [e061d3]
>>>              sibling              (ref4) [43d7492]
>>>  [43d730b]      formal_parameter
>>>                name                 (strp) "sdev"
>>>                decl_file            (data1) 1
>>>                decl_line            (data2) 318
>>>                type                 (ref4) [43d22ff]
>>>                location             (data4) location list [e06233]

...
> I think I can also see the 5-byte difference here.
> 
>  [e061d3]  0xffffffff81480e80..0xffffffff81480e86 [   0] breg7 8
>            0xffffffff81480e86..0xffffffff81480e89 [   0] breg7 16
>            0xffffffff81480e89..0xffffffff81480f43 [   0] breg6 16
>            0xffffffff81480f43..0xffffffff81480f44 [   0] breg7 8
>  [e06233]  0xffffffff81480e85..0xffffffff81480eae [   0] reg5
>            0xffffffff81480edf..0xffffffff81480f36 [   0] reg3

Right, so your function starts at e80, while sdev starts at e85.

> Output of objdump -d:
> ffffffff81480e80 <scsi_device_unbusy>:
> ffffffff81480e80:       e8 7b 6c 22 00          callq
> ffffffff816a7b00 <__fentry__>
> ffffffff81480e85:       55                      push   %rbp
> ffffffff81480e86:       48 89 e5                mov    %rsp,%rbp
> ffffffff81480e89:       48 83 ec 20             sub    $0x20,%rsp

And indeed it lines up with the fentry call.

> I added lines in the source code of systemtap to print msg when
> dwflpp::pr15123_retry_addr returns 0.
> The problem is that the producer string returned by
> dwarf_formstring(&cudie_producer) is "GNU C 4.6.3". There isn't
> "-mfentry". I guess that is what you mean.

Yes.

> Do you want me to use -grecord-gcc-switches to rebuilt the kernel?

Yes, it appears this is needed.  Or if you're building your own
SystemTap, you could just patch out the lines which look for mfentry.
The heuristic is erring on the side of caution, so we don't produce
invalid data.  In any case, gcc 4.8 has fixed this issue directly.

For the record, I figured out that Fedora actually has
-grecord-gcc-switches by default for the whole distro in gcc.spec, with
this:
> sed -i '/dwarf_record_gcc_switches/s/Init(0)/Init(1)/' gcc/common.opt

^ permalink raw reply	[flat|nested] 12+ messages in thread

end of thread, other threads:[~2013-05-29  0:19 UTC | newest]

Thread overview: 12+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2013-02-05  6:35 [BUG] syscall.unlink no longer works after upgrading kernel to 3.7.3 agentzh
2013-02-05  8:57 ` Mark Wielaard
2013-02-05 17:30   ` Josh Stone
2013-05-28 18:53     ` Zheng Da
2013-05-28 19:15       ` Mark Wielaard
2013-05-28 19:57         ` Zheng Da
2013-05-28 20:22           ` Josh Stone
2013-05-28 20:32             ` Mark Wielaard
2013-05-28 21:36               ` Zheng Da
2013-05-28 22:51                 ` Josh Stone
2013-05-28 23:52                   ` Zheng Da
2013-05-29  0:19                     ` Josh Stone

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).